Hi everyone,
Yesterday one of our mysql servers (mysq-server-5.0.32-7etch1 on debian
4.0 AMD64) has crashed with this messages:
Feb 24 18:19:50 vs1 mysqld[3665]: 080224 18:19:50 [ERROR]
/usr/sbin/mysqld: Incorrect key file for table '/tmp/#sql_e50_9.MYI';
try to repair it
Feb 24 18:19:50 vs1 mysqld[3665]: 080224 18:19:50 [ERROR]
/usr/sbin/mysqld: Incorrect key file for table '/tmp/#sql_e50_18.MYI';
try to repair it
Feb 24 18:19:50 vs1 mysqld[3665]: 080224 18:19:50 [ERROR]
/usr/sbin/mysqld: Incorrect key file for table '/tmp/#sql_e50_15.MYI';
try to repair it
Feb 24 18:19:50 vs1 mysqld[3665]: 080224 18:19:50 [ERROR]
/usr/sbin/mysqld: Incorrect key file for table '/tmp/#sql_e50_21.MYI';
try to repair it
Feb 24 18:19:50 vs1 mysqld[3665]: *** glibc detected *** double free or
corruption (!prev): 0x000000000a364800 ***
Feb 24 18:19:50 vs1 mysqld[3665]: mysqld got signal 6;
Feb 24 18:19:50 vs1 mysqld[3665]: This could be because you hit a bug.
It is also possible that this binary
Feb 24 18:19:50 vs1 mysqld[3665]: or one of the libraries it was linked
against is corrupt, improperly built,
Feb 24 18:19:50 vs1 mysqld[3665]: or misconfigured. This error can also
be caused by malfunctioning hardware.
Feb 24 18:19:50 vs1 mysqld[3665]: We will try our best to scrape up some
info that will hopefully help diagnose
Feb 24 18:19:50 vs1 mysqld[3665]: the problem, but since we have already
crashed, something is definitely wrong
Feb 24 18:19:50 vs1 mysqld[3665]: and this may fail.
Feb 24 18:19:50 vs1 mysqld[3665]:
Feb 24 18:19:50 vs1 mysqld[3665]: key_buffer_size=268435456
Feb 24 18:19:50 vs1 mysqld[3665]: read_buffer_size=131072
Feb 24 18:19:50 vs1 mysqld[3665]: max_used_connections=479
Feb 24 18:19:50 vs1 mysqld[3665]: max_connections=2048
Feb 24 18:19:50 vs1 mysqld[3665]: threads_connected=60
Feb 24 18:19:50 vs1 mysqld[3665]: It is possible that mysqld could use up to
Feb 24 18:19:50 vs1 mysqld[3665]: key_buffer_size + (read_buffer_size +
sort_buffer_size)*max_connections = 268959728 K
Feb 24 18:19:50 vs1 mysqld[3665]: bytes of memory
Feb 24 18:19:50 vs1 mysqld[3665]: Hope that's ok; if not, decrease some
variables in the equation.
Feb 24 18:19:50 vs1 mysqld[3665]:
Feb 24 18:19:50 vs1 mysqld[3665]: thd=0x2aaaaab5e800
Feb 24 18:19:50 vs1 mysqld[3665]: Attempting backtrace. You can use the
following information to find out
Feb 24 18:19:50 vs1 mysqld[3665]: where mysqld died. If you see no
messages after this, something went
Feb 24 18:19:50 vs1 mysqld[3665]: terribly wrong...
Feb 24 18:19:50 vs1 mysqld[3665]: Cannot determine thread,
fp=0x45b52190, backtrace may not be correct.
Feb 24 18:19:50 vs1 mysqld[3665]: Bogus stack limit or frame pointer,
fp=0x45b52190, stack_bottom=0x45b50000, thread_stack=1048576, aborting
backtrace.
Feb 24 18:19:50 vs1 mysqld[3665]: Trying to get some variables.
Feb 24 18:19:50 vs1 mysqld[3665]: Some pointers may be invalid and cause
the dump to abort...
Feb 24 18:19:50 vs1 mysqld[3665]: thd->query at 0xa2da7f0 = SELECT
p.`id`, t.`title`, IFNULL(p.`modified`, p.`created`) AS `timestamp`,
Feb 24 18:19:50 vs1 mysqld[3665]: CONCAT_WS('/', f.`filename`,
CONCAT_WS('-', s.`filename`, FLOOR(COUNT(DISTINCT atp.`thread`) / 20)),
Feb 24 18:19:50 vs1 mysqld[3665]: CONCAT_WS('-',
FLOOR((COUNT(DISTINCT ap.`id`) - 1) / 20), t.`filename`)) AS `path`
Feb 24 18:19:50 vs1 mysqld[3665]: FROM `thread` AS t
Feb 24 18:19:50 vs1 mysqld[3665]: INNER JOIN `post` AS p ON
t.`newest_post` = p.`id`
Feb 24 18:19:50 vs1 mysqld[3665]: INNER JOIN `post_content` AS pc ON
pc.`id` = p.`id`
Feb 24 18:19:50 vs1 mysqld[3665]: INNER JOIN `post` AS ap ON
ap.`thread` = t.`id`
Feb 24 18:19:50 vs1 mysqld[3665]: INNER JOIN `subforum` AS s ON
t.`subforum` = s.`id`
Feb 24 18:19:50 vs1 mysqld[3665]: INNER JOIN `main_forum` AS f ON
s.`main_forum` = f.`id`
Feb 24 18:19:50 vs1 mysqld[3665]: LEFT OUTER JOIN `thread` AS at ON
at.`subforum` = s.`id`
Feb 24 18:19:50 vs1 mysqld[3665]: LEFT OUTER JOIN `post` AS atp ON
atp.`id` = at.`newest_post` AND IFNULL(atp.`modified`, atp.`created`) >
IFNULL(p.`modified`, p.`created`)
Feb 24 18:19:50 vs1 mysqld[3665]: GROUP BY t.`id`
Feb 24 18:19:50 vs1 mysqld[3665]: ORDER BY IFNULL(p.`modified`,
p.`created`) DESC
Feb 24 18:19:50 vs1 mysqld[3665]: LIMIT 10
Feb 24 18:19:50 vs1 mysqld[3665]: thd->thread_id=24695272
Feb 24 18:19:50 vs1 mysqld[3665]: The manual page at
http://www.mysql.com/doc/en/Crashing.html contains
Feb 24 18:19:50 vs1 mysqld[3665]: information that should help you find
out what is causing the crash.
Structure of tables involved in the query is attached. I don't know how
to repeat this crash. It has happened for the first time since the site
(and its forum) was started in 2006. Unfortunately the crash coused (or
was coused by - it's hard to say for me) some corruption in temporary
tables and trying to start mysqld generated other crash (log in
forum-bug-restart1.txt) The server didn't want to start clean until I
deleted /tmp/#sql_*.* . Then mysqlcheck reported during startup that the
`post` and `thread` tables has not been closed properly and they should
be checked with myisam so I did it and next restart of mysqld was
completely clean.
--
Chives
CREATE TABLE `bryk-forum`.`main_forum` (
`id` tinyint(3) unsigned NOT NULL auto_increment,
`title` varchar(255) NOT NULL,
`about` text,
`modified` timestamp NOT NULL default '0000-00-00 00:00:00',
`priority` tinyint(3) unsigned NOT NULL default '0',
`filename` varchar(255) NOT NULL,
`newest_subforum` smallint(5) unsigned NOT NULL,
PRIMARY KEY (`id`),
KEY `idx_priority` (`priority`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 ROW_FORMAT=FIXED;
CREATE TABLE `bryk-forum`.`subforum` (
`id` smallint(5) unsigned NOT NULL auto_increment,
`title` varchar(255) NOT NULL,
`description` text NOT NULL,
`main_forum` tinyint(3) unsigned NOT NULL default '0',
`priority` smallint(5) unsigned NOT NULL default '0',
`filename` varchar(255) NOT NULL,
`newest_thread` int(10) unsigned NOT NULL,
PRIMARY KEY (`id`),
KEY `FK_subforum_main_forum` (`main_forum`),
KEY `idx_priority` (`priority`),
CONSTRAINT `FK_subforum_main_forum` FOREIGN KEY (`main_forum`) REFERENCES
`main_forum` (`id`) ON DELETE CASCADE ON UPDATE CASCADE
) ENGINE=InnoDB DEFAULT CHARSET=utf8 ROW_FORMAT=FIXED;
CREATE TABLE `bryk-forum`.`thread` (
`id` int(10) unsigned NOT NULL auto_increment,
`title` varchar(255) NOT NULL,
`author` int(10) unsigned NOT NULL default '0',
`subforum` smallint(5) unsigned NOT NULL default '0',
`filename` varchar(255) NOT NULL,
`newest_post` bigint(20) unsigned NOT NULL,
PRIMARY KEY (`id`),
KEY `FK_thread_subforum` (`subforum`)
) ENGINE=MyISAM AUTO_INCREMENT=426 DEFAULT CHARSET=utf8 ROW_FORMAT=FIXED;
CREATE TABLE `bryk-forum`.`post` (
`id` bigint(20) unsigned NOT NULL auto_increment,
`created` timestamp NOT NULL default CURRENT_TIMESTAMP,
`author` int(10) unsigned NOT NULL default '1',
`thread` int(10) unsigned NOT NULL default '1',
`modified` timestamp NOT NULL default '0000-00-00 00:00:00',
`raported` bit(2) NOT NULL default '\0',
`words` mediumint(8) unsigned NOT NULL default '0',
`characters` int(10) unsigned NOT NULL default '0',
PRIMARY KEY (`id`),
KEY `idx_created` (`created`),
KEY `idx_thread` (`thread`),
KEY `idx_author` (`author`),
KEY `idx_modified` (`modified`)
) ENGINE=MyISAM AUTO_INCREMENT=24485 DEFAULT CHARSET=utf8
COLLATE=utf8_unicode_ci ROW_FORMAT=FIXED;
CREATE TABLE `bryk-forum`.`post_content` (
`id` int(10) unsigned NOT NULL default '0',
`title` varchar(1024) collate utf8_unicode_ci NOT NULL,
`filename` varchar(0) collate utf8_unicode_ci NOT NULL,
`text` longtext collate utf8_unicode_ci NOT NULL,
`stripped` longtext collate utf8_unicode_ci NOT NULL,
PRIMARY KEY (`id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 COLLATE=utf8_unicode_ci ROW_FORMAT=FIXED;
Feb 25 09:04:47 vs1 mysqld[15168]: 080225 9:04:47 InnoDB: Database was not
shut down normally!
Feb 25 09:04:47 vs1 mysqld[15168]: InnoDB: Starting crash recovery.
Feb 25 09:04:47 vs1 mysqld[15168]: InnoDB: Reading tablespace information from
the .ibd files...
Feb 25 09:04:47 vs1 mysqld[15168]: InnoDB: Restoring possible half-written data
pages from the doublewrite
Feb 25 09:04:47 vs1 mysqld[15168]: InnoDB: buffer...
Feb 25 09:04:47 vs1 mysqld[15168]: 080225 9:04:47 InnoDB: Starting log scan
based on checkpoint at
Feb 25 09:04:47 vs1 mysqld[15168]: InnoDB: log sequence number 172 3421671693.
Feb 25 09:04:47 vs1 mysqld[15168]: InnoDB: Doing recovery: scanned up to log
sequence number 172 3421671693
Feb 25 09:04:48 vs1 mysqld[15168]: InnoDB: Last MySQL binlog file position 0
1362576, file name /data/mysql-log/mysql-bin.000192
Feb 25 09:04:48 vs1 mysqld[15168]: 080225 9:04:48 InnoDB: Started; log
sequence number 172 3421671693
Feb 25 09:04:48 vs1 mysqld[15168]: 080225 9:04:48 [Note] Recovering after a
crash using /data/mysql-log/mysql-bin
Feb 25 09:04:48 vs1 mysqld[15168]: 080225 9:04:48 [Note] Starting crash
recovery...
Feb 25 09:04:48 vs1 mysqld[15168]: 080225 9:04:48 [Note] Crash recovery
finished.
Feb 25 09:04:54 vs1 mysqld[15168]: 080225 9:04:54 [Note] /usr/sbin/mysqld:
ready for connections.
Feb 25 09:04:54 vs1 mysqld[15168]: Version: '5.0.32-Debian_7etch1-log' socket:
'/var/run/mysqld/mysqld.sock' port: 3306 Debian etch distribution
Feb 25 09:04:54 vs1 mysqld[15168]: 080225 9:04:54 InnoDB: Error: trying to
declare trx to enter InnoDB, but
Feb 25 09:04:54 vs1 mysqld[15168]: InnoDB: it already is declared.
Feb 25 09:04:54 vs1 mysqld[15168]: TRANSACTION 0 1042039893, ACTIVE 0 sec,
process no 15167, OS thread id 1093708128, thread declared inside InnoDB 0
Feb 25 09:04:54 vs1 mysqld[15168]: mysql tables in use 1, locked 1
Feb 25 09:04:54 vs1 mysqld[15168]: 1 lock struct(s), heap size 368
Feb 25 09:04:54 vs1 mysqld[15168]: MySQL thread id 3, query id 120 vs2.bryk.pl
194.33.187.232 bryk-users update
Feb 25 09:04:54 vs1 mysqld[15168]: INSERT INTO `session` (`sid`, `ip`,
`created`, `hitted`, `data`)
Feb 25 09:04:54 vs1 mysqld[15168]: VALUES ('61320f34909cfeddf6bcd4291f844167',
'1371456883', NOW(), NOW(), '')
Feb 25 09:04:54 vs1 mysqld[15168]: ON DUPLICATE KEY UPDATE
Feb 25 09:04:54 vs1 mysqld[15168]: ^I`ip`^I^I= VALUES(`ip`),
Feb 25 09:04:54 vs1 mysqld[15168]: ^I`created`^I= VALUES(`created`),
Feb 25 09:04:54 vs1 mysqld[15168]: ^I`hitted`^I= VALUES(`hitted`),
Feb 25 09:04:54 vs1 mysqld[15168]: ^I`data`^I^I= VALUES(`data`)
Feb 25 09:04:54 vs1 mysqld[15168]:
Feb 25 09:04:55 vs1 mysqld[15168]: 080225 9:04:55 InnoDB: Error: trying to
declare trx to enter InnoDB, but
Feb 25 09:04:55 vs1 mysqld[15168]: InnoDB: it already is declared.
Feb 25 09:04:55 vs1 mysqld[15168]: TRANSACTION 0 1042039931, ACTIVE 0 sec,
process no 15167, OS thread id 1096866144, thread declared inside InnoDB 0
Feb 25 09:04:55 vs1 mysqld[15168]: mysql tables in use 1, locked 1
Feb 25 09:04:55 vs1 mysqld[15168]: 1 lock struct(s), heap size 368
Feb 25 09:04:55 vs1 mysqld[15168]: MySQL thread id 6, query id 399 vs2.bryk.pl
194.33.187.232 bryk-users update
Feb 25 09:04:55 vs1 mysqld[15168]: INSERT INTO `session_log` (`session`,
`timestamp`, `text`)
Feb 25 09:04:55 vs1 mysqld[15168]: VALUES (21232589, NOW(), '18551')
Feb 25 09:04:55 vs1 mysqld[15168]:
Feb 25 09:04:59 vs1 mysqld[15168]: 080225 9:04:59 [ERROR] /usr/sbin/mysqld:
Incorrect key file for table '/tmp/#sql_3b3f_9.MYI'; try to repair it
Feb 25 09:04:59 vs1 mysqld[15168]: 080225 9:04:59 [ERROR] /usr/sbin/mysqld:
Incorrect key file for table '/tmp/#sql_3b3f_6.MYI'; try to repair it
Feb 25 09:04:59 vs1 mysqld[15168]: 080225 9:04:59 [ERROR] /usr/sbin/mysqld:
Incorrect key file for table '/tmp/#sql_3b3f_12.MYI'; try to repair it
Feb 25 09:04:59 vs1 mysqld[15168]: 080225 9:04:59 [ERROR] /usr/sbin/mysqld:
Incorrect key file for table '/tmp/#sql_3b3f_15.MYI'; try to repair it
Feb 25 09:04:59 vs1 mysqld[15168]: 080225 9:04:59 [ERROR] /usr/sbin/mysqld:
Incorrect key file for table '/tmp/#sql_3b3f_24.MYI'; try to repair it
Feb 25 09:04:59 vs1 mysqld[15168]: 080225 9:04:59 [ERROR] /usr/sbin/mysqld:
Incorrect key file for table '/tmp/#sql_3b3f_0.MYI'; try to repair it
Feb 25 09:04:59 vs1 mysqld[15168]: *** glibc detected *** double free or
corruption (out): 0x00002aaaab11c9a0 ***
Feb 25 09:04:59 vs1 mysqld[15168]: mysqld got signal 6;
Feb 25 09:04:59 vs1 mysqld[15168]: This could be because you hit a bug. It is
also possible that this binary
Feb 25 09:04:59 vs1 mysqld[15168]: or one of the libraries it was linked
against is corrupt, improperly built,
Feb 25 09:04:59 vs1 mysqld[15168]: or misconfigured. This error can also be
caused by malfunctioning hardware.
Feb 25 09:04:59 vs1 mysqld[15168]: We will try our best to scrape up some info
that will hopefully help diagnose
Feb 25 09:04:59 vs1 mysqld[15168]: the problem, but since we have already
crashed, something is definitely wrong
Feb 25 09:04:59 vs1 mysqld[15168]: and this may fail.
Feb 25 09:04:59 vs1 mysqld[15168]:
Feb 25 09:04:59 vs1 mysqld[15168]: key_buffer_size=268435456
Feb 25 09:04:59 vs1 mysqld[15168]: read_buffer_size=131072
Feb 25 09:04:59 vs1 mysqld[15168]: max_used_connections=69
Feb 25 09:04:59 vs1 mysqld[15168]: max_connections=2048
Feb 25 09:04:59 vs1 mysqld[15168]: threads_connected=69
Feb 25 09:04:59 vs1 mysqld[15168]: It is possible that mysqld could use up to
Feb 25 09:04:59 vs1 mysqld[15168]: key_buffer_size + (read_buffer_size +
sort_buffer_size)*max_connections = 268959728 K
Feb 25 09:04:59 vs1 mysqld[15168]: bytes of memory
Feb 25 09:04:59 vs1 mysqld[15168]: Hope that's ok; if not, decrease some
variables in the equation.
Feb 25 09:04:59 vs1 mysqld[15168]:
Feb 25 09:04:59 vs1 mysqld[15168]: thd=0x2aaaaafaeb60
Feb 25 09:04:59 vs1 mysqld[15168]: Attempting backtrace. You can use the
following information to find out
Feb 25 09:04:59 vs1 mysqld[15168]: where mysqld died. If you see no messages
after this, something went
Feb 25 09:04:59 vs1 mysqld[15168]: terribly wrong...
Feb 25 09:04:59 vs1 mysqld[15168]: Cannot determine thread, fp=0x44c43190,
backtrace may not be correct.
Feb 25 09:04:59 vs1 mysqld[15168]: Bogus stack limit or frame pointer,
fp=0x44c43190, stack_bottom=0x44c40000, thread_stack=1048576, aborting
backtrace.
Feb 25 09:04:59 vs1 mysqld[15168]: Trying to get some variables.
Feb 25 09:04:59 vs1 mysqld[15168]: Some pointers may be invalid and cause the
dump to abort...
Feb 25 09:04:59 vs1 mysqld[15168]: thd->query at 0x2aaaaad4b090 is invalid
pointer
Feb 25 09:04:59 vs1 mysqld[15168]: thd->thread_id=60
Feb 25 09:04:59 vs1 mysqld[15168]: The manual page at
http://www.mysql.com/doc/en/Crashing.html contains
Feb 25 09:04:59 vs1 mysqld[15168]: information that should help you find out
what is causing the crash.
