Bug #16218 | Crash on insert delayed | ||
---|---|---|---|
Submitted: | 5 Jan 2006 10:04 | Modified: | 11 Jul 2006 8:59 |
Reporter: | Olaf van der Spek (Basic Quality Contributor) | Email Updates: | |
Status: | Closed | Impact on me: | |
Category: | MySQL Server: MyISAM storage engine | Severity: | S1 (Critical) |
Version: | 5.0.16 and 5.0.18 Debian/5.0.21BK | OS: | Linux (Debian/Suse Linux) |
Assigned to: | Ingo Strüwing | CPU Architecture: | Any |
[5 Jan 2006 10:04]
Olaf van der Spek
[5 Jan 2006 12:22]
MySQL Verification Team
I was unable to repeat with current source code on Linux and with 5.0.18 on Windows. Which package are you used? our binaries or Debian's? Thanks in advance. miguel@hegel:~/dbs/5.0> bin/mysql -uroot test Reading table information for completion of table and column names You can turn off this feature to get a quicker startup with -A Welcome to the MySQL monitor. Commands end with ; or \g. Your MySQL connection id is 1 to server version: 5.0.19-debug Type 'help;' or '\h' for help. Type '\c' to clear the buffer. mysql> CREATE TABLE `xwi_login_failures` ( -> `ipa` int(11) NOT NULL default '0', -> `gsku` int(11) NOT NULL default '0', -> `name` varchar(9) NOT NULL default '', -> `pass` varchar(8) NOT NULL default '', -> `serial` varchar(22) default NULL, -> `sid` int(11) NOT NULL default '0', -> `msg` varchar(255) NOT NULL default '', -> `time` int(11) NOT NULL default '0' -> ) ENGINE=MyISAM DEFAULT CHARSET=latin1; Query OK, 0 rows affected (0.01 sec) mysql> mysql> insert delayed into xwi_login_failures (ipa, gsku, name, pass, serial, -> sid, msg, time) values (0,0,"","",NULL,0,"",0); Query OK, 1 row affected (0.01 sec) mysql> select version(); +--------------+ | version() | +--------------+ | 5.0.19-debug | +--------------+ 1 row in set (0.00 sec) mysql>
[5 Jan 2006 15:22]
Olaf van der Spek
Debian packages. I can't reproduce it on a less loaded server either, so I guess some load is required. Does the stack trace provide any hints?
[5 Jan 2006 23:19]
MySQL Verification Team
Can you provide the dump for the table with enough rows for to do the test? If yes you can upload it at: ftp://ftp.mysql.com:/pub/mysql/upload Thanks in advance.
[6 Jan 2006 15:41]
Olaf van der Spek
There are 5799457 rows in the table (118934 kbyte), but it appears to not depend on the number of rows as on a second server with the same number it doesn't crash either. I think it depends on the 'load' (other server activity).
[26 Jan 2006 2:20]
o s
I've noticed the same exact behavior but on Ubuntu (a Debian derivative). It is extremely difficult to reproduce because it always happens under heavy load (2500+ delayed inserts per second with 80+ clients). But no 24 hour period ever passes without a crash. Here are my delayed insert settings: delayed_insert_limit 5000 delayed_insert_timeout 300 delayed_queue_size 10000 max_delayed_threads 20 max_insert_delayed_threads 20
[27 Jan 2006 16:32]
o s
Some additional information on my previous entry: I have tried to run the application with no DELAYED inserts, but the crashes still persist, so this bug is probably different from the one reported originally by Olaf van der Spek. The crashes only occur on a very heavily loaded system. The crashes occur on the following binaries: Linux AMD 64 5.0.17 Standard Linux AMD 64 5.0.18 Standard Linux AMD 64 5.0.18 Debug There is never a stack trace in the error log, just the following message: 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=8589934592 read_buffer_size=4190208 max_used_connections=94 max_connections=250 threads_connected=94 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 10435606 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. The machine has 32GB of memory so that is not an issue.
[3 Feb 2006 7:33]
Olaf van der Spek
I've noticed the data in the tables used is getting corrupted. Sometimes the values are length-prefixed (binary), sometimes left padded.
[14 Feb 2006 11:47]
Valeriy Kravchuk
Is this table created in 5.0.x or in previous version of MySQL?
[14 Feb 2006 12:50]
Olaf van der Spek
In a previous version.
[8 Mar 2006 14:01]
MySQL Verification Team
Thank you for the feedback. Are you able for to test this issue making a dump from the previous version and to reload in 5.0.18 version?. There are similar issues when an upgrade was done over a previous version. Thanks in advance.
[8 Mar 2006 19:36]
Olaf van der Spek
Would a truncate table also recreate the able in the new format? And is there a way to find out the format version?
[9 Mar 2006 13:09]
Olaf van der Spek
Recreating the table appears to be a work around.
[30 Mar 2006 4:03]
Wade Bowmer
I've found a situation very similar to this bug in 5.0.19. As far as I can determine (and I'm still digging), MyISAM tables created as version 7 or older - that's MySQL 4.0 or older - with VARCHAR() fields crash a database thread on a DELAYED INSERT. Re-creating the table appears to solve the problem because it creates them as version 10. As it happens, I created a new table, renamed tables and did an INSERT ... SELECT ... from the old table, but I imagine an ALTER TABLE [table name] TYPE=MyISAM would work. Wade.
[5 Apr 2006 12:21]
Jim Driscoll
I'm seeing something very similar on RHEL4/5.0.19: # resolve_stack_dump -s /usr/lib/mysql/mysqld.sym -n mysql.stack 0x815a810 handle_segfault + 610 0xbdb8b8 (?) (nil) 0x81bc4dd _Z12mysql_insertP3THDP13st_table_listR4ListI4ItemERS3_IS5_ES6_S6_15enum_duplicatesb + 2901 0x8172473 _Z21mysql_execute_commandP3THD + 15599 0x8175d2d _Z11mysql_parseP3THDPcj + 305 0x81764c1 _Z16dispatch_command19enum_server_commandP3THDPcj + 1675 0x8177294 _Z10do_commandP3THD + 134 0x8177920 handle_one_connection + 1438 0xbd6080 (?) 0xb0623e (?) That's on an INSERT DELAYED... VALUES... Although it's far from reproducible, it does always happen on the same table name in this case (different databases, perhaps, but the same table name). The table structure is: CREATE TABLE `nuke_blocked_pagetracker` ( `id` int(11) NOT NULL auto_increment, `id_tracker` int(11) default NULL, `last_page` varchar(250) default NULL, `page_date` int(11) unsigned NOT NULL default '0', PRIMARY KEY (`id`), KEY `id_tracker` (`id_tracker`) ) ENGINE=MyISAM DEFAULT CHARSET=latin1 Previously I've seen this behaviour on indexed (and not since OPTIMIZEd) TEXT columns, but that's clearly not the case here. Redoing the insert to the same table structure (ie, a newly created table using the above statement) is fine; redoing the insert to the same table (assuming not much else happened in the interim) is fine. Example statement: thd->query at 0x8fb8ff8 = INSERT DELAYED INTO nuke_blocked_pagetracker (last_pag e ,page_date ,id_tracker) VALUES ('/modules.php?name=Top', '1144072611', '133') With this same style of statement, we've also had some: Stack range sanity check OK, backtrace follows: 0x815a810 0xbdb8b8 Stack trace seems successful - bottom reached ...which is plainly wrong.
[6 Apr 2006 21:12]
MySQL Verification Team
I was able to repeat this issue with server 5.0.21 and not with server 5.1.9 following the below procedure sequence: Create tha database and table with server version 4.0.XX: miguel@hegel:~/dbs/4.0> bin/mysqladmin -uroot create db55 miguel@hegel:~/dbs/4.0> bin/mysql -uroot db55 Welcome to the MySQL monitor. Commands end with ; or \g. Your MySQL connection id is 2 to server version: 4.0.27-debug-log Type 'help;' or '\h' for help. Type '\c' to clear the buffer. mysql> CREATE TABLE `xwi_login_failures` ( -> `ipa` int(11) NOT NULL default '0', -> `gsku` int(11) NOT NULL default '0', -> `name` varchar(9) NOT NULL default '', -> `pass` varchar(8) NOT NULL default '', -> `serial` varchar(22) default NULL, -> `sid` int(11) NOT NULL default '0', -> `msg` varchar(255) NOT NULL default '', -> `time` int(11) NOT NULL default '0' -> ) ENGINE=MyISAM; Query OK, 0 rows affected (0.01 sec) mysql> Then just copy the database and its table to 5.0.XX data directory and issue the insert delayed command: miguel@hegel:~/dbs/5.0> bin/mysql -uroot db55 Reading table information for completion of table and column names You can turn off this feature to get a quicker startup with -A Welcome to the MySQL monitor. Commands end with ; or \g. Your MySQL connection id is 1 to server version: 5.0.21-debug Type 'help;' or '\h' for help. Type '\c' to clear the buffer. mysql> insert delayed into xwi_login_failures (ipa, gsku, name, pass, serial, -> sid, msg, time) values (0,0,"","",NULL,0,"",0); ERROR 2013 (HY000): Lost connection to MySQL server during query mysql> exit Bye Back Trace: 060406 18:03:01 [Note] /home/miguel/dbs/5.0/libexec/mysqld: ready for connections. Version: '5.0.21-debug' socket: '/tmp/mysql.sock' port: 3306 Source distribution [New Thread 1131862960 (LWP 5884)] [New Thread 1132063664 (LWP 5885)] Program received signal SIGSEGV, Segmentation fault. [Switching to Thread 1131862960 (LWP 5884)] 0x0816fa85 in Field::set_null (this=0x8e84918, row_offset=0) at field.h:197 197 { if (null_ptr) null_ptr[row_offset]|= null_bit; } (gdb) bt full #0 0x0816fa85 in Field::set_null (this=0x8e84918, row_offset=0) at field.h:197 No locals. #1 0x08309df1 in set_field_to_null_with_conversions (field=0x8e84918, no_conversions=false) at field_conv.cc:156 No locals. #2 0x08159116 in Item_null::save_in_field (this=0x8e83dd8, field=0x8e84918, no_conversions=false) at item.cc:4017 No locals. #3 0x0822e964 in fill_record (thd=0x8e64060, fields=@0x8e64528, values=@0x8e83bb8, ignore_errors=false) at sql_base.cc:4820 rfield = (class Field *) 0x8e84918 table = (TABLE *) 0x8e83fe8 value = (class Item *) 0x8e83dd8 _db_func_ = 0x0 _db_file_ = 0x5 <Address 0x5 out of bounds> f = {<base_list_iterator> = {list = 0x8e64528, el = 0x8e839e8, prev = 0x0, current = 0x0}, <No data fields>} v = {<base_list_iterator> = {list = 0x8e83bb8, el = 0x8e83e48, prev = 0x0, current = 0x0}, <No data fields>} field = (class Item_field *) 0x8e83960 _db_level_ = 0 _db_framep_ = (char **) 0x0 #4 0x0822ea4a in fill_record_n_invoke_before_triggers (thd=0x8e64060, fields=@0x8e64528, values=@0x8e83bb8, ignore_errors=false, triggers=0x0, event=TRG_EVENT_INSERT) at sql_base.cc:4861 No locals. <cut>
[7 Apr 2006 7:56]
Jim Driscoll
Miguel: If you can reproduce this reliably, try doing the same but with "OPTIMIZE TABLE xwi_login_failures" run from the MySQL 5.0 client after the table's been copied over, but before the INSERT DELAYED, or if that still causes the problem, try "ALTER TABLE xwi_login_failures ENGINE=MyISAM" as mentioned by Wade above. I don't know about everyone else, but if I can work around this with some simple SQL commands, then I want to do that. However, of course, Miguel may be encountering a different problem with the same basic symptom...
[8 Jun 2006 15:38]
Ingo Strüwing
Test script part 1 to be used on MySQL 4.x before using part 2.
Attachment: bug16218-1.sh (application/x-sh, text), 3.98 KiB.
[8 Jun 2006 15:39]
Ingo Strüwing
Test script part 2 to be used on MySQL 5.0 after part 1 was used on MySQL 4.x.
Attachment: bug16218-2.sh (application/x-sh, text), 4.34 KiB.
[8 Jun 2006 15:55]
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/7408
[9 Jun 2006 16:36]
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/7448
[9 Jun 2006 18:50]
Ingo Strüwing
It turned out that the above fix did not cover the whole problem. The correct fix does also solve Bug#13707, Bug#17294, and Bug#16611. The problem was that copying fields converted old varchar fields to new varchar fields. This resulted in a different interpretation of the record contents between the foreground thread and the delayed insert thread.
[9 Jun 2006 18:53]
Ingo Strüwing
Test script part 1 for all four bugs to be used on MySQL 4.1 before using part 2.
Attachment: bug16218-1.sh (application/x-sh, text), 5.50 KiB.
[9 Jun 2006 18:54]
Ingo Strüwing
Test script part 2 for all four bugs to be used on MySQL 5.0 after part 1 was used on MySQL 4.1.
Attachment: bug16218-2.sh (application/x-sh, text), 6.19 KiB.
[9 Jun 2006 20: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/7462
[16 Jun 2006 0:54]
Michael Widenius
Review done by email; Did suggest a cleaner approach how to solve this problem.
[21 Jun 2006 17:46]
Tordjman Yohan
Mysql 5.0.23-20060619 (cvs) bugs too on insert delayed. if i set max_delayed_thread to 0 , the mysqld don't crash... Sample trace: 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=681574400 read_buffer_size=1044480 max_used_connections=45 max_connections=400 threads_connected=2 It is possible that mysqld could use up to key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 1892796 K bytes of memory Hope that's ok; if not, decrease some variables in the equation. thd=0x80114b20 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=0x83e7d9c8, backtrace may not be correct. Stack range sanity check OK, backtrace follows: 0x816787c 0xffffe420 (nil) 0x81d612b 0x8184b6a 0x81875c1 0x8187bca 0x81898f7 0xb7f47ced 0xb7d88d7e 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 0x870fa50 = INSERT DELAYED INTO nuke_blocked_pagetracker (last_page ,page_date ,id_tracker) VALUES ('/modules.php?name=News&new_topic=17', '1150844260', '3774') thd->thread_id=245645 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
[26 Jun 2006 18:57]
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/8261
[6 Jul 2006 17:36]
Ingo Strüwing
Pushed to mysql-5.1-engines.
[6 Jul 2006 19:49]
Ingo Strüwing
Pushed to mysql-5.0-engines.
[8 Jul 2006 17:15]
Ingo Strüwing
INSERT DELAYED crashed in 5.0 on a table with a varchar that could be NULL and was created pre-5.0 (Bugs 16218 and 13707). INSERT DELAYED corrupted data in 5.0 on a table with varchar fields that was created pre-5.0 (Bugs 17294 and 16611). In case of INSERT DELAYED the open table is copied from the delayed insert thread to be able to create a record for the queue. When copying the fields, a method was used that did convert old varchar to new varchar fields and did not set up some pointers into the record buffer of the table. The field conversion was guilty for the misinterpretation of the record contents by the delayed insert thread. The wrong pointer setup was guilty for the crashes. For Bug 13707 (Server crash with INSERT DELAYED on MyISAM table) I fixed the above mentioned method to set up one of the pointers. For Bug 16218 I set up the other pointers too. But when looking at the corruptions I got aware that converting the field type was totally wrong for INSERT DELAYED. The copied table is used to create a record that is to be sent to the delayed insert thread. Of course it can interpret the record correctly only if all field types are the same in both table objects. So I revoked the fix for Bug 13707 and changed the new_field() method so that it can suppress conversions. Pushed to 5.1.12 and 5.0.24.
[11 Jul 2006 8:59]
MC Brown
Documented in the 5.0 and 5.1 changelog: Using tables from MySQL 4.x in MySQL 5.x, in particular those with <literal>VARCHAR</literal> fields and using <literal>INSERT DELAYED</literal> to update data in the table would result in either data corruption or a server crash. (Bug #16611, Bug #16218, Bug #17294)
[13 Jul 2006 3:33]
Paul DuBois
5.0.x fix went to 5.0.25 instead.
[12 Sep 2006 13:38]
Valeriy Kravchuk
Bug #22244 was marked as a duplicate of this one.