MySQL Lists are EOL. Please join:

List:General Discussion« Previous MessageNext Message »
From:Heikki Tuuri Date:November 25 2003 9:29am
Subject:Re: InnoDB caused crash and left me a log entry...
View as plain text  
Bruce,

I am not able to repeat the crash. I tested on Linux with 4.0.17.

You have the index

KEY `jiveForum_name_idx` (`name`(10)),

The bug is probably in the column prefix index. That feature was introduced
in 4.0.14. Did you create the table with a version < 4.0.14? What kinds of
operations have you done with the table? Updates, deletes?

The failing assertion is the one below. InnoDB has determined that a
secondary index record is alphabetically equal to the new value (which is
understandable, because in your update the first 10 characters do not
change), but it turns out that the field length is NOT the same in the
updated value.

If I cannot repeat the crash, I will add diagnostic code to that place
anyway, so that we get more information of the bug. Also note that OS X is
not as well tested as Linux. There may be file corruption bugs in OS X.

Please send me a dump of the table for more testing, and also your my.cnf.

Best regards,

Heikki Tuuri
Innobase Oy
http://www.innodb.com
Foreign keys, transactions, and row level locking for MySQL
InnoDB Hot Backup - hot backup tool for InnoDB which also backs up MyISAM
tables

Order MySQL technical support from https://order.mysql.com/



/*******************************************************************
Builds an update vector from those fields which in a secondary index entry
differ from a record that has the equal ordering fields. NOTE: we compare
the fields as binary strings! */

upd_t*
row_upd_build_sec_rec_difference_binary(
/*====================================*/
                                /* out, own: update vector of differing
                                fields */
        dict_index_t*   index,  /* in: index */
        dtuple_t*       entry,  /* in: entry to insert */
        rec_t*          rec,    /* in: secondary index record */
        mem_heap_t*     heap)   /* in: memory heap from which allocated */
{
        upd_field_t*    upd_field;
        dfield_t*       dfield;
        byte*           data;
        ulint           len;
        upd_t*          update;
        ulint           n_diff;
        ulint           i;

        /* This function is used only for a secondary index */
        ut_ad(0 == (index->type & DICT_CLUSTERED));

        update = upd_create(dtuple_get_n_fields(entry), heap);

        n_diff = 0;

        for (i = 0; i < dtuple_get_n_fields(entry); i++) {

                data = rec_get_nth_field(rec, i, &len);

                dfield = dtuple_get_nth_field(entry, i);

                ut_a(len == dfield_get_len(dfield));


----- Original Message ----- 
From: "Bruce Dembecki" <bruce@stripped>
Newsgroups: mailing.database.myodbc
Sent: Tuesday, November 25, 2003 7:28 AM
Subject: InnoDB caused crash and left me a log entry...


> InnoDB seems to have crashed on us, and put the errors below into the log
> files... It took several crashes and some time but I was able to isolate
the
> extremely simple query involved.
>
> Server is OSX 10.3 running on a Dual 200MHZ G5 with 4Gigs ram. MySQL is
> 4.0.16.
>
> The original queries to crash were a little longer in that they also
updated
> the field "description" with a large block of text as well as the field
> "name". The following Queries repeatedly caused a crash when executed from
> the mysql command line directly to mysqld with no other client connections
> open:
>
> update jiveForum set name='Technical Questions: SDK' where forumID=4;
> update jiveForum set name="Technical Questions: SDK" where forumID=4;
> update jiveForum set name='Technical Questions - SDK' where forumID=4;
> update jiveForum set name='Technical Questions' where forumID=4;
>
> These queries did not cause the crash:
>
> update jiveForum set name='Technical' where forumID=4;
> update jiveForum set name='SDK Questions' where forumID=4;
>
> I eventually moved the table out of InnoDB, made the changes, and moved it
> back to InnoDB again without experiencing further problems. In order to
> restore client services I did not try again to reproduce the problem,
> instant Database server crash is not an attractive experience, especially
in
> our production environment.
>
> The table in question has 12 rows and looks like this:
>
> CREATE TABLE `jiveForum` (
>   `forumID` bigint(20) NOT NULL default '0',
>   `name` varchar(255) binary NOT NULL default '',
>   `description` text,
>   `modDefaultThreadVal` bigint(20) NOT NULL default '0',
>   `modMinThreadVal` bigint(20) NOT NULL default '0',
>   `modDefaultMsgVal` bigint(20) NOT NULL default '0',
>   `modMinMsgVal` bigint(20) NOT NULL default '0',
>   `creationDate` varchar(15) NOT NULL default '',
>   `modifiedDate` varchar(15) NOT NULL default '',
>   `categoryID` bigint(20) NOT NULL default '1',
>   `categoryIndex` int(11) NOT NULL default '0',
>   PRIMARY KEY  (`forumID`),
>   UNIQUE KEY `name` (`name`),
>   KEY `jiveForum_name_idx` (`name`(10)),
>   KEY `jiveForum_cat_idx` (`categoryID`),
>   KEY `jiveForum_catIndex_idx` (`categoryIndex`)
> ) TYPE=InnoDB
>
> Below are the logs of the first two crashes and some additional comments
> from yours truly.
>
> Best Regards, Bruce
>
> 031124 16:27:18  InnoDB: Assertion failure in thread 2167428608 in file
> row0upd.c line 713
> InnoDB: Failing assertion: len == dfield_get_len(dfield)
> InnoDB: We intentionally generate a memory trap.
> InnoDB: Send a detailed bug report to mysql@stripped
> InnoDB: Thread 2168107008 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 8529408 stopped in file sync0arr.c line 126
> InnoDB: Thread 8954880 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 12103168 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 8530432 stopped in file ../../innobase/include/sync0sync.ic
> line 109
> InnoDB: Thread 11085312 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 12269056 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 9271296 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2166052864 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 15272448 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2166610432 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 14812160 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2166472704 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2166551552 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2167671808 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 15742976 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 15535616 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 16771584 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2166734336 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 15129088 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 13153792 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2166089216 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2166471680 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2167336448 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 10588160 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 9951744 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 9901056 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 14827520 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 12161536 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 9560576 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2164816384 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 13114368 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2164369408 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2166552576 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2166132224 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 9431552 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 9461760 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 14631424 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 9867264 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 13056512 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 11888640 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2165679616 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 8592896 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 9804800 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 11084288 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 11851776 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2167690752 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 12045312 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2167689728 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2167337472 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 14834688 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 9014272 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 9391104 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 15273472 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 14998016 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 9984000 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2167120896 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2166743040 stopped in file
> ../../innobase/include/sync0sync.ic line 109
> InnoDB: Thread 10562560 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 10530816 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 13377536 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 8432128 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 9156608 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2168107008 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 8529408 stopped in file sync0arr.c line 127
> InnoDB: Thread 8954880 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 12103168 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 8530432 stopped in file ../../innobase/include/sync0sync.ic
> line 109
> InnoDB: Thread 11085312 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 12269056 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 9271296 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2166052864 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 15272448 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2166610432 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 14812160 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2166472704 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2166551552 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2167671808 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 15742976 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 15535616 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 16771584 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2166734336 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 15129088 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 13153792 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2166089216 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2166471680 stopped in file ha_innodb.cc line 2025
> InnoDB: Thread 2167336448 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 10588160 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 9951744 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 9901056 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 14827520 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 12161536 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 9560576 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2164816384 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 13114368 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2164369408 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2166552576 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2166132224 stopped in file ha_innodb.cc line 2025
> InnoDB: Thread 9461760 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 14631424 stopped in file
../../innobase/include/sync0sync.ic
> line 109
> InnoDB: Thread 9867264 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 13056512 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 11888640 stopped in file sync0arr.c line 336
> InnoDB: Thread 2165679616 stopped in file ha_innodb.cc line 2025
> InnoDB: Thread 8592896 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 9804800 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 11084288 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 11851776 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2167690752 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 12045312 stopped in file sync0arr.c line 336
> InnoDB: Thread 2167689728 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2167337472 stopped in file sync0arr.c line 336
> InnoDB: Thread 14834688 stopped in file ha_innodb.cc line 2025
> InnoDB: Thread 9014272 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 9391104 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 15273472 stopped in file ha_innodb.cc line 2025
> InnoDB: Thread 14998016 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 9984000 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2167120896 stopped in file ha_innodb.cc line 396
> InnoDB: Thread 2166743040 stopped in file
> ../../innobase/include/sync0sync.ic line 109
>
>
> Comments - In this first case the crash took place over an extended period
> as InnoDB became unavailable and stopped answering requests... The number
of
> threads in use grew rapidly and as you can see here it appears each of
them
> was stopped. After giving up attempts to clear the problem I attempted to
> shutdown the server, it did not respond to shutdown requests, and
eventually
> it crashed... Here is the restart that then took place, as you can see it
> took mere seconds for the serve to come up and again run into the
> Assertation failure and reboot itself:
>
>
> 031124 16:50:02  mysqld started
> 031124 16:50:05  InnoDB: Database was not shut down normally.
> InnoDB: Starting recovery from log files...
> InnoDB: Starting log scan based on checkpoint at
> InnoDB: log sequence number 99 1589503740
> InnoDB: Doing recovery: scanned up to log sequence number 99 1589574112
> 031124 16:50:05  InnoDB: Starting an apply batch of log records to the
> database...
> InnoDB: Progress in percents: 1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18
> 19 20
>  21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44
45
> 46 4
> 7 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 64 65 66 67 68 69 70 71
72
> 73
> 74 75 76 77 78 79 80 81 82 83 84 85 86 87 88 89 90 91 92 93 94 95 96 97 98
> 99
> InnoDB: Apply batch completed
> InnoDB: In a MySQL replication slave the last master binlog file
> InnoDB: position 0 931902160, file name binary-log.010
> InnoDB: Last MySQL binlog file position 0 878923518, file name
> /mysqlarchive/binlogs/binary-log.010
> 031124 16:50:08  InnoDB: Flushing modified pages from the buffer pool...
> InnoDB: Error: tablespace size stored in header is 2438400 pages, but
> InnoDB: the sum of data file sizes is 2560000 pages
> 031124 16:50:09  InnoDB: Started
> 031124 16:50:09  Slave I/O thread: connected to master 'xxxx@mysql1:3306',
> replication started in log 'binary-log.010' at position 938273194
> /usr/local/mysql/bin/mysqld: ready for connections.
> Version: '4.0.16-standard-log'  socket: '/tmp/mysql.sock'  port: 3306
> 031124 16:50:09  InnoDB: Assertion failure in thread 8766464 in file
> row0upd.c line 713
> InnoDB: Failing assertion: len == dfield_get_len(dfield)
> InnoDB: We intentionally generate a memory trap.
> InnoDB: Send a detailed bug report to mysql@stripped
> InnoDB: Thread 8946176 stopped in file ../../innobase/include/sync0sync.ic
> line 109
> InnoDB: Thread 8528384 stopped in file os0sync.c line 501
> InnoDB: Thread 8530432 stopped in file ../../innobase/include/sync0sync.ic
> line 109
> mysqld got signal 10;
> 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=16777216
> read_buffer_size=2093056
> max_used_connections=53
> max_connections=1000
> threads_connected=54
> It is possible that mysqld could use up to
> key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections =
> 410837
> 6 K
> bytes of memory
> Hope that's ok; if not, decrease some variables in the equation.
>
>
> Number of processes running now: 2
> 031124 16:50:10  mysqld restarted
>
>
> After this the logs stop being interesting, more of the same... Under more
> controlled circumstances the crash was immediately fatal... In this case
> more controlled means not firing up all the nodes that usually connect to
> this server and thus not having other threads running at the time, nor
> having that 4 week uptime the machine had before this occurred, so little
to
> no memory actually filled. It was reproduced over seven times in a five
> minute period using nothing other than a command line connection from
mysql
> to mysqld on this database with the queries indicated above... Each time
the
> connection would immediately close and the server would restart. The same
> queries caused no ill effect when I converted the table to MyISAM, and
> converting it back to InnoDB with the resultant change also caused no ill
> affect. Once this conversion was done I did not again attempt to reproduce
> the crash.
>
>
> -- 
> MySQL General Mailing List
> For list archives: http://lists.mysql.com/mysql
> To unsubscribe:
http://lists.mysql.com/mysql?unsub=1
>

Thread
InnoDB caused crash and left me a log entry...Bruce Dembecki25 Nov
Re: InnoDB caused crash and left me a log entry...Heikki Tuuri25 Nov
  • Re: InnoDB caused crash and left me a log entry...Bruce Dembecki25 Nov