I have a linux server built from a standard dell workstation. 1 500g sata II drive, core 2 duo, 1g ram. It is running Ubuntu server 8.04 with mysql (InnoDB tables), php, apache, and Zabbix. The primary role of this server is to monitor our other production servers using an open source monitoring application called Zabbix.
We had a large electrical/tornado storm one day and power went out to the zabbix server. This server did not have a battery backup. When the power was restored, the zabbix PHP apache frontend was not functional. I logged in to the zabbix server via SSH and found the mysql service to be stopped. Trying to restart the service failed. There was a descriptive log entry in /var/log/syslog about mysql every time the server rebooted, or I tried to restart the mysql service.
/etc/syslog mysql error
Jun 16 10:30:22 zabbix mysqld_safe[3209]: started Jun 16 10:30:22 zabbix mysqld[3212]: 090616 10:30:22 [Warning] Can't create test file /var/lib/mysql/zabbix.lower-test Jun 16 10:30:22 zabbix mysqld[3212]: 090616 10:30:22 [Warning] Can't create test file /var/lib/mysql/zabbix.lower-test Jun 16 10:30:22 zabbix mysqld[3212]: 090616 10:30:22 [Warning] One can only use the --user switch if running as root Jun 16 10:30:22 zabbix mysqld[3212]: Jun 16 10:30:22 zabbix mysqld[3212]: 090616 10:30:22 InnoDB: Operating system error number 13 in a file operation. Jun 16 10:30:22 zabbix mysqld[3212]: InnoDB: The error means mysqld does not have the access rights to Jun 16 10:30:22 zabbix mysqld[3212]: InnoDB: the directory. Jun 16 10:30:22 zabbix mysqld[3212]: InnoDB: File name ./ibdata1 Jun 16 10:30:22 zabbix mysqld[3212]: InnoDB: File operation call: 'open'. Jun 16 10:30:22 zabbix mysqld[3212]: InnoDB: Cannot continue operation. Jun 16 10:30:22 zabbix mysqld_safe[3219]: ended Jun 16 10:34:17 zabbix mysqld_safe[3307]: started Jun 16 10:34:17 zabbix mysqld[3310]: InnoDB: Log scan progressed past the checkpoint lsn 23 1887506125 Jun 16 10:34:17 zabbix mysqld[3310]: 090616 10:34:17 InnoDB: Database was not shut down normally! Jun 16 10:34:17 zabbix mysqld[3310]: InnoDB: Starting crash recovery. Jun 16 10:34:17 zabbix mysqld[3310]: InnoDB: Reading tablespace information from the .ibd files... Jun 16 10:34:17 zabbix mysqld[3310]: InnoDB: Restoring possible half-written data pages from the doublewrite Jun 16 10:34:17 zabbix mysqld[3310]: InnoDB: buffer... Jun 16 10:34:20 zabbix kernel: [430257.964516] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 Jun 16 10:34:20 zabbix kernel: [430257.964567] ata1.00: BMDMA stat 0x24 Jun 16 10:34:20 zabbix kernel: [430257.964604] ata1.00: cmd 25/00:08:d5:af:de/00:00:2d:00:00/e0 tag 0 dma 4096 in Jun 16 10:34:20 zabbix kernel: [430257.964606] res 51/40:00:d9:af:de/40:00:2d:00:00/00 Emask 0x9 (media error) Jun 16 10:34:20 zabbix kernel: [430257.964722] ata1.00: status: { DRDY ERR } Jun 16 10:34:20 zabbix kernel: [430257.964752] ata1.00: error: { UNC } Jun 16 10:34:20 zabbix kernel: [430258.102146] ata1.00: configured for UDMA/133 Jun 16 10:34:20 zabbix kernel: [430258.102169] ata1: EH complete Jun 16 10:34:23 zabbix kernel: [430260.962859] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 Jun 16 10:34:23 zabbix kernel: [430260.962909] ata1.00: BMDMA stat 0x24 Jun 16 10:34:23 zabbix kernel: [430260.962953] ata1.00: cmd 25/00:08:d5:af:de/00:00:2d:00:00/e0 tag 0 dma 4096 in Jun 16 10:34:23 zabbix kernel: [430260.962955] res 51/40:00:d9:af:de/40:00:2d:00:00/00 Emask 0x9 (media error) Jun 16 10:34:23 zabbix kernel: [430260.963840] ata1.00: status: { DRDY ERR } Jun 16 10:34:23 zabbix kernel: [430260.963869] ata1.00: error: { UNC } Jun 16 10:34:23 zabbix kernel: [430261.090611] ata1.00: configured for UDMA/133 Jun 16 10:34:23 zabbix kernel: [430261.090636] ata1: EH complete Jun 16 10:34:26 zabbix kernel: [430263.903147] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 Jun 16 10:34:26 zabbix kernel: [430263.903197] ata1.00: BMDMA stat 0x24 Jun 16 10:34:26 zabbix kernel: [430263.903240] ata1.00: cmd 25/00:08:d5:af:de/00:00:2d:00:00/e0 tag 0 dma 4096 in Jun 16 10:34:26 zabbix kernel: [430263.903242] res 51/40:00:d9:af:de/40:00:2d:00:00/00 Emask 0x9 (media error) Jun 16 10:34:26 zabbix kernel: [430263.903359] ata1.00: status: { DRDY ERR } Jun 16 10:34:26 zabbix kernel: [430263.903388] ata1.00: error: { UNC } Jun 16 10:34:26 zabbix kernel: [430264.030611] ata1.00: configured for UDMA/133 Jun 16 10:34:26 zabbix kernel: [430264.030629] ata1: EH complete Jun 16 10:34:29 zabbix kernel: [430266.884955] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 Jun 16 10:34:29 zabbix kernel: [430266.885005] ata1.00: BMDMA stat 0x24 Jun 16 10:34:29 zabbix kernel: [430266.885049] ata1.00: cmd 25/00:08:d5:af:de/00:00:2d:00:00/e0 tag 0 dma 4096 in Jun 16 10:34:29 zabbix kernel: [430266.885051] res 51/40:00:d9:af:de/40:00:2d:00:00/00 Emask 0x9 (media error) Jun 16 10:34:29 zabbix kernel: [430266.885167] ata1.00: status: { DRDY ERR } Jun 16 10:34:29 zabbix kernel: [430266.885197] ata1.00: error: { UNC } Jun 16 10:34:29 zabbix kernel: [430267.020601] ata1.00: configured for UDMA/133 Jun 16 10:34:29 zabbix kernel: [430267.020619] ata1: EH complete Jun 16 10:34:32 zabbix /etc/init.d/mysql[3465]: 0 processes alive and '/usr/bin/mysqladmin --defaults-file=/etc/mysql/debian.cnf ping' resulted in Jun 16 10:34:32 zabbix /etc/init.d/mysql[3465]: ^G/usr/bin/mysqladmin: connect to server at 'localhost' failed Jun 16 10:34:32 zabbix /etc/init.d/mysql[3465]: error: 'Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (2)' Jun 16 10:34:32 zabbix /etc/init.d/mysql[3465]: Check that mysqld is running and that the socket: '/var/run/mysqld/mysqld.sock' exists! Jun 16 10:34:32 zabbix /etc/init.d/mysql[3465]: Jun 16 10:34:32 zabbix kernel: [430269.891721] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 Jun 16 10:34:32 zabbix kernel: [430269.891772] ata1.00: BMDMA stat 0x24 Jun 16 10:34:32 zabbix kernel: [430269.891809] ata1.00: cmd 25/00:08:d5:af:de/00:00:2d:00:00/e0 tag 0 dma 4096 in Jun 16 10:34:32 zabbix kernel: [430269.891811] res 51/40:00:d9:af:de/40:00:2d:00:00/00 Emask 0x9 (media error) Jun 16 10:34:32 zabbix kernel: [430269.891927] ata1.00: status: { DRDY ERR } Jun 16 10:34:32 zabbix kernel: [430269.891956] ata1.00: error: { UNC } Jun 16 10:34:32 zabbix kernel: [430270.011242] ata1.00: configured for UDMA/133 Jun 16 10:34:32 zabbix kernel: [430270.011260] ata1: EH complete Jun 16 10:34:35 zabbix kernel: [430272.865280] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 Jun 16 10:34:35 zabbix kernel: [430272.865325] ata1.00: BMDMA stat 0x24 Jun 16 10:34:35 zabbix kernel: [430272.865362] ata1.00: cmd 25/00:08:d5:af:de/00:00:2d:00:00/e0 tag 0 dma 4096 in Jun 16 10:34:35 zabbix kernel: [430272.865365] res 51/40:00:d9:af:de/40:00:2d:00:00/00 Emask 0x9 (media error) Jun 16 10:34:35 zabbix kernel: [430272.865485] ata1.00: status: { DRDY ERR } Jun 16 10:34:35 zabbix kernel: [430272.865514] ata1.00: error: { UNC } Jun 16 10:34:35 zabbix mysqld[3310]: InnoDB: Error: tried to read 16384 bytes at offset 0 3142926336. Jun 16 10:34:35 zabbix mysqld[3310]: InnoDB: Was only able to read 4096. Jun 16 10:34:35 zabbix mysqld[3310]: InnoDB: Fatal error: cannot read from file. OS error number 17. Jun 16 10:34:35 zabbix mysqld[3310]: 090616 10:34:35InnoDB: Assertion failure in thread 3083065024 in file os0file.c line 2211 Jun 16 10:34:35 zabbix mysqld[3310]: InnoDB: We intentionally generate a memory trap. Jun 16 10:34:35 zabbix mysqld[3310]: InnoDB: Submit a detailed bug report to http://bugs.mysql.com. Jun 16 10:34:35 zabbix mysqld[3310]: InnoDB: If you get repeated assertion failures or crashes, even Jun 16 10:34:35 zabbix mysqld[3310]: InnoDB: immediately after the mysqld startup, there may be Jun 16 10:34:35 zabbix mysqld[3310]: InnoDB: corruption in the InnoDB tablespace. Please refer to Jun 16 10:34:35 zabbix mysqld[3310]: InnoDB: http://dev.mysql.com/doc/refman/5.0/en/forcing-recovery.html Jun 16 10:34:35 zabbix mysqld[3310]: InnoDB: about forcing recovery. Jun 16 10:34:35 zabbix mysqld[3310]: 090616 10:34:35 - mysqld got signal 11 ; Jun 16 10:34:35 zabbix kernel: [430273.000614] ata1.00: configured for UDMA/133 Jun 16 10:34:35 zabbix mysqld[3310]: This could be because you hit a bug. It is also possible that this binary Jun 16 10:34:35 zabbix kernel: [430273.000639] sd 0:0:0:0: [sda] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE,SUGGEST_OK Jun 16 10:34:35 zabbix mysqld[3310]: or one of the libraries it was linked against is corrupt, improperly built, Jun 16 10:34:35 zabbix mysqld[3310]: or misconfigured. This error can also be caused by malfunctioning hardware. Jun 16 10:34:35 zabbix mysqld[3310]: We will try our best to scrape up some info that will hopefully help diagnose Jun 16 10:34:35 zabbix mysqld[3310]: the problem, but since we have already crashed, something is definitely wrong Jun 16 10:34:35 zabbix mysqld[3310]: and this may fail. Jun 16 10:34:35 zabbix mysqld[3310]: Jun 16 10:34:35 zabbix mysqld[3310]: key_buffer_size=0 Jun 16 10:34:35 zabbix mysqld[3310]: read_buffer_size=131072 Jun 16 10:34:35 zabbix mysqld[3310]: max_used_connections=0 Jun 16 10:34:35 zabbix mysqld[3310]: max_connections=100 Jun 16 10:34:35 zabbix mysqld[3310]: threads_connected=0 Jun 16 10:34:35 zabbix mysqld[3310]: It is possible that mysqld could use up to Jun 16 10:34:35 zabbix mysqld[3310]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 217599 K Jun 16 10:34:35 zabbix mysqld[3310]: bytes of memory Jun 16 10:34:35 zabbix mysqld[3310]: Hope that's ok; if not, decrease some variables in the equation. Jun 16 10:34:35 zabbix mysqld[3310]: Jun 16 10:34:35 zabbix mysqld[3310]: thd=(nil) Jun 16 10:34:35 zabbix mysqld[3310]: Attempting backtrace. You can use the following information to find out Jun 16 10:34:35 zabbix mysqld[3310]: where mysqld died. If you see no messages after this, something went Jun 16 10:34:35 zabbix mysqld[3310]: terribly wrong... Jun 16 10:34:35 zabbix mysqld[3310]: Cannot determine thread, fp=0xbfb6f428, backtrace may not be correct. Jun 16 10:34:35 zabbix mysqld[3310]: Stack range sanity check OK, backtrace follows: Jun 16 10:34:35 zabbix mysqld[3310]: 0x81f82e6 Jun 16 10:34:35 zabbix mysqld[3310]: 0x843d4a9 Jun 16 10:34:35 zabbix mysqld[3310]: 0x843e2d7 Jun 16 10:34:35 zabbix mysqld[3310]: 0x84094b6 Jun 16 10:34:35 zabbix mysqld[3310]: 0x83c4e39 Jun 16 10:34:35 zabbix mysqld[3310]: 0x83eb5b1 Jun 16 10:34:35 zabbix mysqld[3310]: 0x83ef927 Jun 16 10:34:35 zabbix mysqld[3310]: 0x83f028d Jun 16 10:34:35 zabbix mysqld[3310]: 0x83f083d Jun 16 10:34:35 zabbix mysqld[3310]: Stack trace seems successful - bottom reached Jun 16 10:34:35 zabbix mysqld[3310]: Please read http://dev.mysql.com/doc/mysql/en/using-stack-trace.html and follow instructions on how to resolve the stack trace. Resolved Jun 16 10:34:35 zabbix mysqld[3310]: stack trace is much more helpful in diagnosing the problem, so please do Jun 16 10:34:35 zabbix mysqld[3310]: resolve it Jun 16 10:34:35 zabbix mysqld[3310]: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains Jun 16 10:34:35 zabbix mysqld[3310]: information that should help you find out what is causing the crash. Jun 16 10:34:35 zabbix mysqld_safe[3471]: ended Jun 16 10:34:35 zabbix kernel: [430273.000646] sd 0:0:0:0: [sda] Sense Key : Medium Error [current] [descriptor] Jun 16 10:34:35 zabbix kernel: [430273.000654] Descriptor sense data with sense descriptors (in hex): Jun 16 10:34:35 zabbix kernel: [430273.000659] 72 03 11 04 00 00 00 0c 00 0a 80 00 00 00 00 00 Jun 16 10:34:35 zabbix kernel: [430273.000677] 2d de af d9 Jun 16 10:34:35 zabbix kernel: [430273.000684] sd 0:0:0:0: [sda] Add. Sense: Unrecovered read error - auto reallocate failed Jun 16 10:34:35 zabbix kernel: [430273.000694] end_request: I/O error, dev sda, sector 769568729 Jun 16 10:34:35 zabbix kernel: [430273.000751] ata1: EH complete Jun 16 10:34:35 zabbix kernel: [430273.001635] sd 0:0:0:0: [sda] 976773168 512-byte hardware sectors (500108 MB) Jun 16 10:34:35 zabbix kernel: [430273.002048] sd 0:0:0:0: [sda] Write Protect is off Jun 16 10:34:35 zabbix kernel: [430273.002051] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00 Jun 16 10:34:35 zabbix kernel: [430273.002873] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA Jun 16 10:34:35 zabbix kernel: [430273.004033] sd 0:0:0:0: [sda] 976773168 512-byte hardware sectors (500108 MB) Jun 16 10:34:35 zabbix kernel: [430273.004545] sd 0:0:0:0: [sda] Write Protect is off Jun 16 10:34:35 zabbix kernel: [430273.004548] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00 Jun 16 10:34:35 zabbix kernel: [430273.005386] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA Jun 16 10:36:52 zabbix logger: Shorewall restarted Jun 16 10:37:46 zabbix mysqld_safe[5258]: started Jun 16 10:37:46 zabbix mysqld[5261]: InnoDB: Log scan progressed past the checkpoint lsn 23 1887506125 Jun 16 10:37:46 zabbix mysqld[5261]: 090616 10:37:46 InnoDB: Database was not shut down normally! Jun 16 10:37:46 zabbix mysqld[5261]: InnoDB: Starting crash recovery. Jun 16 10:37:46 zabbix mysqld[5261]: InnoDB: Reading tablespace information from the .ibd files... Jun 16 10:37:46 zabbix mysqld[5261]: InnoDB: Restoring possible half-written data pages from the doublewrite Jun 16 10:37:46 zabbix mysqld[5261]: InnoDB: buffer... Jun 16 10:37:49 zabbix kernel: [430466.768136] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 Jun 16 10:37:49 zabbix kernel: [430466.768187] ata1.00: BMDMA stat 0x24 Jun 16 10:37:49 zabbix kernel: [430466.768224] ata1.00: cmd 25/00:08:d5:af:de/00:00:2d:00:00/e0 tag 0 dma 4096 in Jun 16 10:37:49 zabbix kernel: [430466.768226] res 51/40:00:d9:af:de/40:00:2d:00:00/00 Emask 0x9 (media error) Jun 16 10:37:49 zabbix kernel: [430466.768342] ata1.00: status: { DRDY ERR } Jun 16 10:37:49 zabbix kernel: [430466.768372] ata1.00: error: { UNC } Jun 16 10:37:49 zabbix kernel: [430466.891871] ata1.00: configured for UDMA/133 Jun 16 10:37:49 zabbix kernel: [430466.891892] ata1: EH complete Jun 16 10:37:52 zabbix kernel: [430469.766669] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 Jun 16 10:37:52 zabbix kernel: [430469.766718] ata1.00: BMDMA stat 0x24 Jun 16 10:37:52 zabbix kernel: [430469.766761] ata1.00: cmd 25/00:08:d5:af:de/00:00:2d:00:00/e0 tag 0 dma 4096 in Jun 16 10:37:52 zabbix kernel: [430469.766763] res 51/40:00:d9:af:de/40:00:2d:00:00/00 Emask 0x9 (media error) Jun 16 10:37:52 zabbix kernel: [430469.766880] ata1.00: status: { DRDY ERR } Jun 16 10:37:52 zabbix kernel: [430469.766909] ata1.00: error: { UNC } Jun 16 10:37:52 zabbix kernel: [430469.900584] ata1.00: configured for UDMA/133 Jun 16 10:37:52 zabbix kernel: [430469.900600] ata1: EH complete Jun 16 10:37:55 zabbix kernel: [430472.781826] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 Jun 16 10:37:55 zabbix kernel: [430472.781876] ata1.00: BMDMA stat 0x24 Jun 16 10:37:55 zabbix kernel: [430472.781913] ata1.00: cmd 25/00:08:d5:af:de/00:00:2d:00:00/e0 tag 0 dma 4096 in Jun 16 10:37:55 zabbix kernel: [430472.781915] res 51/40:00:d9:af:de/40:00:2d:00:00/00 Emask 0x9 (media error) Jun 16 10:37:55 zabbix kernel: [430472.782032] ata1.00: status: { DRDY ERR } Jun 16 10:37:55 zabbix kernel: [430472.782061] ata1.00: error: { UNC } Jun 16 10:37:55 zabbix kernel: [430472.910622] ata1.00: configured for UDMA/133 Jun 16 10:37:55 zabbix kernel: [430472.910641] ata1: EH complete Jun 16 10:37:58 zabbix kernel: [430475.755307] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 Jun 16 10:37:58 zabbix kernel: [430475.755356] ata1.00: BMDMA stat 0x24 Jun 16 10:37:58 zabbix kernel: [430475.755399] ata1.00: cmd 25/00:08:d5:af:de/00:00:2d:00:00/e0 tag 0 dma 4096 in Jun 16 10:37:58 zabbix kernel: [430475.755401] res 51/40:00:d9:af:de/40:00:2d:00:00/00 Emask 0x9 (media error) Jun 16 10:37:58 zabbix kernel: [430475.755517] ata1.00: status: { DRDY ERR } Jun 16 10:37:58 zabbix kernel: [430475.755547] ata1.00: error: { UNC } Jun 16 10:37:58 zabbix kernel: [430475.860606] ata1.00: configured for UDMA/133 Jun 16 10:37:58 zabbix kernel: [430475.860625] ata1: EH complete Jun 16 10:38:00 zabbix /etc/init.d/mysql[5416]: 0 processes alive and '/usr/bin/mysqladmin --defaults-file=/etc/mysql/debian.cnf ping' resulted in Jun 16 10:38:00 zabbix /etc/init.d/mysql[5416]: ^G/usr/bin/mysqladmin: connect to server at 'localhost' failed Jun 16 10:38:00 zabbix /etc/init.d/mysql[5416]: error: 'Can't connect to local MySQL server through socket '/var/run/mysqld/mysqld.sock' (2)' Jun 16 10:38:00 zabbix /etc/init.d/mysql[5416]: Check that mysqld is running and that the socket: '/var/run/mysqld/mysqld.sock' exists! Jun 16 10:38:00 zabbix /etc/init.d/mysql[5416]: Jun 16 10:38:01 zabbix kernel: [430478.712161] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 Jun 16 10:38:01 zabbix kernel: [430478.712211] ata1.00: BMDMA stat 0x24 Jun 16 10:38:01 zabbix kernel: [430478.712255] ata1.00: cmd 25/00:08:d5:af:de/00:00:2d:00:00/e0 tag 0 dma 4096 in Jun 16 10:38:01 zabbix kernel: [430478.712259] res 51/40:00:d9:af:de/40:00:2d:00:00/00 Emask 0x9 (media error) Jun 16 10:38:01 zabbix kernel: [430478.712376] ata1.00: status: { DRDY ERR } Jun 16 10:38:01 zabbix kernel: [430478.712405] ata1.00: error: { UNC } Jun 16 10:38:01 zabbix kernel: [430478.840601] ata1.00: configured for UDMA/133 Jun 16 10:38:01 zabbix kernel: [430478.840618] ata1: EH complete Jun 16 10:38:04 zabbix kernel: [430481.710682] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x0 Jun 16 10:38:04 zabbix kernel: [430481.710728] ata1.00: BMDMA stat 0x24 Jun 16 10:38:04 zabbix kernel: [430481.710769] ata1.00: cmd 25/00:08:d5:af:de/00:00:2d:00:00/e0 tag 0 dma 4096 in Jun 16 10:38:04 zabbix kernel: [430481.710771] res 51/40:00:d9:af:de/40:00:2d:00:00/00 Emask 0x9 (media error) Jun 16 10:38:04 zabbix kernel: [430481.710889] ata1.00: status: { DRDY ERR } Jun 16 10:38:04 zabbix kernel: [430481.710919] ata1.00: error: { UNC } Jun 16 10:38:04 zabbix mysqld[5261]: InnoDB: Error: tried to read 16384 bytes at offset 0 3142926336. Jun 16 10:38:04 zabbix mysqld[5261]: InnoDB: Was only able to read 4096. Jun 16 10:38:04 zabbix mysqld[5261]: InnoDB: Fatal error: cannot read from file. OS error number 17. Jun 16 10:38:04 zabbix mysqld[5261]: 090616 10:38:04InnoDB: Assertion failure in thread 3084031680 in file os0file.c line 2211 Jun 16 10:38:04 zabbix mysqld[5261]: InnoDB: We intentionally generate a memory trap. Jun 16 10:38:04 zabbix mysqld[5261]: InnoDB: Submit a detailed bug report to http://bugs.mysql.com. Jun 16 10:38:04 zabbix mysqld[5261]: InnoDB: If you get repeated assertion failures or crashes, even Jun 16 10:38:04 zabbix mysqld[5261]: InnoDB: immediately after the mysqld startup, there may be Jun 16 10:38:04 zabbix mysqld[5261]: InnoDB: corruption in the InnoDB tablespace. Please refer to Jun 16 10:38:04 zabbix mysqld[5261]: InnoDB: http://dev.mysql.com/doc/refman/5.0/en/forcing-recovery.html Jun 16 10:38:04 zabbix mysqld[5261]: InnoDB: about forcing recovery. Jun 16 10:38:04 zabbix mysqld[5261]: 090616 10:38:04 - mysqld got signal 11 ; Jun 16 10:38:04 zabbix mysqld[5261]: This could be because you hit a bug. It is also possible that this binary Jun 16 10:38:04 zabbix mysqld[5261]: or one of the libraries it was linked against is corrupt, improperly built, Jun 16 10:38:04 zabbix mysqld[5261]: or misconfigured. This error can also be caused by malfunctioning hardware. Jun 16 10:38:04 zabbix mysqld[5261]: We will try our best to scrape up some info that will hopefully help diagnose Jun 16 10:38:04 zabbix mysqld[5261]: the problem, but since we have already crashed, something is definitely wrong Jun 16 10:38:04 zabbix mysqld[5261]: and this may fail. Jun 16 10:38:04 zabbix mysqld[5261]: Jun 16 10:38:04 zabbix mysqld[5261]: key_buffer_size=0 Jun 16 10:38:04 zabbix mysqld[5261]: read_buffer_size=131072 Jun 16 10:38:04 zabbix mysqld[5261]: max_used_connections=0 Jun 16 10:38:04 zabbix mysqld[5261]: max_connections=100 Jun 16 10:38:04 zabbix mysqld[5261]: threads_connected=0 Jun 16 10:38:04 zabbix mysqld[5261]: It is possible that mysqld could use up to Jun 16 10:38:04 zabbix mysqld[5261]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 217599 K Jun 16 10:38:04 zabbix mysqld[5261]: bytes of memory Jun 16 10:38:04 zabbix mysqld[5261]: Hope that's ok; if not, decrease some variables in the equation. Jun 16 10:38:04 zabbix mysqld[5261]: Jun 16 10:38:04 zabbix mysqld[5261]: thd=(nil) Jun 16 10:38:04 zabbix mysqld[5261]: Attempting backtrace. You can use the following information to find out Jun 16 10:38:04 zabbix mysqld[5261]: where mysqld died. If you see no messages after this, something went Jun 16 10:38:04 zabbix mysqld[5261]: terribly wrong... Jun 16 10:38:04 zabbix mysqld[5261]: Cannot determine thread, fp=0xbfb5ac18, backtrace may not be correct. Jun 16 10:38:04 zabbix mysqld[5261]: Stack range sanity check OK, backtrace follows: Jun 16 10:38:04 zabbix kernel: [430481.840592] ata1.00: configured for UDMA/133 Jun 16 10:38:04 zabbix mysqld[5261]: 0x81f82e6 Jun 16 10:38:04 zabbix mysqld[5261]: 0x843d4a9 Jun 16 10:38:04 zabbix mysqld[5261]: 0x843e2d7 Jun 16 10:38:04 zabbix mysqld[5261]: 0x84094b6 Jun 16 10:38:04 zabbix mysqld[5261]: 0x83c4e39 Jun 16 10:38:04 zabbix mysqld[5261]: 0x83eb5b1 Jun 16 10:38:04 zabbix mysqld[5261]: 0x83ef927 Jun 16 10:38:04 zabbix mysqld[5261]: 0x83f028d Jun 16 10:38:04 zabbix mysqld[5261]: 0x83f083d Jun 16 10:38:04 zabbix mysqld[5261]: 0x8345004 Jun 16 10:38:04 zabbix mysqld[5261]: 0x82bf4b2 Jun 16 10:38:04 zabbix mysqld[5261]: 0x82b490b Jun 16 10:38:04 zabbix mysqld[5261]: 0x81f93dd Jun 16 10:38:04 zabbix mysqld[5261]: 0x81fb6d3 Jun 16 10:38:04 zabbix mysqld[5261]: 0xb7d41685 Jun 16 10:38:04 zabbix mysqld[5261]: 0x8167d41 Jun 16 10:38:04 zabbix mysqld[5261]: New value of fp=(nil) failed sanity check, terminating stack trace! Jun 16 10:38:04 zabbix mysqld[5261]: Please read http://dev.mysql.com/doc/mysql/en/using-stack-trace.html and follow instructions on how to resolve the stack trace. Resolved Jun 16 10:38:04 zabbix mysqld[5261]: stack trace is much more helpful in diagnosing the problem, so please do Jun 16 10:38:04 zabbix mysqld[5261]: resolve it Jun 16 10:38:04 zabbix mysqld[5261]: The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains Jun 16 10:38:04 zabbix mysqld[5261]: information that should help you find out what is causing the crash. Jun 16 10:38:04 zabbix kernel: [430481.840612] sd 0:0:0:0: [sda] Result: hostbyte=DID_OK driverbyte=DRIVER_SENSE,SUGGEST_OK Jun 16 10:38:04 zabbix kernel: [430481.840619] sd 0:0:0:0: [sda] Sense Key : Medium Error [current] [descriptor] Jun 16 10:38:04 zabbix kernel: [430481.840627] Descriptor sense data with sense descriptors (in hex): Jun 16 10:38:04 zabbix kernel: [430481.840632] 72 03 11 04 00 00 00 0c 00 0a 80 00 00 00 00 00 Jun 16 10:38:04 zabbix kernel: [430481.840658] 2d de af d9 Jun 16 10:38:04 zabbix kernel: [430481.840666] sd 0:0:0:0: [sda] Add. Sense: Unrecovered read error - auto reallocate failed Jun 16 10:38:04 zabbix kernel: [430481.840676] end_request: I/O error, dev sda, sector 769568729 Jun 16 10:38:04 zabbix kernel: [430481.840736] ata1: EH complete Jun 16 10:38:04 zabbix kernel: [430481.841144] sd 0:0:0:0: [sda] 976773168 512-byte hardware sectors (500108 MB) Jun 16 10:38:04 zabbix kernel: [430481.841599] sd 0:0:0:0: [sda] Write Protect is off Jun 16 10:38:04 zabbix kernel: [430481.841602] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00 Jun 16 10:38:04 zabbix kernel: [430481.842416] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA Jun 16 10:38:04 zabbix mysqld_safe[5422]: ended Jun 16 10:38:04 zabbix kernel: [430481.844548] sd 0:0:0:0: [sda] 976773168 512-byte hardware sectors (500108 MB) Jun 16 10:38:04 zabbix kernel: [430481.845046] sd 0:0:0:0: [sda] Write Protect is off Jun 16 10:38:04 zabbix kernel: [430481.845049] sd 0:0:0:0: [sda] Mode Sense: 00 3a 00 00 Jun 16 10:38:04 zabbix kernel: [430481.846048] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
My first plan of action was to search the web for 'Fatal error: cannot read from file. OS error number 17' which \ led me to the usual InnoDB corruption fixers. I also browsed to the web pages the log listed. All of the usual \ mysqlcheck, etc... remedies did not work for me because the database engine (service) would not even start.
After browsing the logs a little more, I noticed the line end_request: I/O error, dev sda, sector 769568729 Which made me think it was an HD error, not a mysql error.
I googled that and found the best way to fix this is to run a fsck -cc to find and mark bad sectors. But \ you MUST do fsck on an unmounted partition or you will possibly ruin your filesystem. So I booted the server \ from a KNOPPIX usb stick (the KNOPPIX with LXDE as it's desktop environment, 6 something). I made sure that the drive did not \ get auto mounted by running umount /dev/sda3. I then ran fsck --help where I did not find the -cc or -c option. \ KNOPPIX was using a different version of fsck that google noted. I remembered that fsck actually uses several \ other programs to do its dirty work, most notably e2fsck. So a e2fsck --help revealed the -c option. And a \ man e2fsck revealed that if you use -c twice (-cc) then it checks for bad blocks in a NON destructive manner. \ I believe a -c could damage or overwrite your data? Maybe to be used on an empty drive to verify integrity before using. So I ran a
# e2fsck -cc /dev/sda3
which took about 15 hours to complete (on the sata II 500gb HD with only 4.6g used).
After e2fsck finished, I rebooted and mysql started! But said something about 'mysql not cleanly closed and upgrade needing tables', but it did \ start and work. I googled that error and it said to run a CHECK TABLE and REPAIR TABLE from the mysql \ terminal. I did that and found a table called history_uint in the zabbix database that was corrupt. I tried \ the REPAIR TABLE history_unit and it simply said 'the storage engine for the table doesn't support repair'. \ So I figured maybe zabbix wasn't InnoDB, so running a
SELECT ENGINE FROM information_schema.TABLES WHERE TABLE_SCHEMA = 'history_uint'
did reveal it was InnoDB. So I googled the 'doesn't support repair' error and found http://dev.mysql.com/doc/refman/5.0/en/mysqlcheck.html.
So I tried the mysqlcheck and mysqlrepair and still received the same error. Reading the above url it says if \ you do receive this error, goto http://dev.mysql.com/doc/refman/5.0/en/rebuilding-tables.html to rebuild \ the corrupt table manually by simply dumping the table and reloading it.
So I ran a
mysqldump -uroot -p zabbix history_uint > dump.sql
which took about 1 minute and wrote a 183mb dump.sql file (table had 1.8 million records)
The dump.sql had the 'create table' routine and a 'dump if exists' routine, so simply running
mysql -uroot -p zabbix < dump.sql
deleted the bad table, created the new table, and inserted all the data, this took about 5 minutes.
After that I started the mysql service with /etc/init.d/mysql start and I did not get the error! Yes.
I rebooted the server and watched the bootup text go by and it said 'mysql not cleanly closed and upgrade' again. ?
I stopped the service, then started it and it gave the same error, strange. I ran a 'mysqlcheck -uroot -p zabbix' \ to check all tables and they all came back and OK, I checked all other databases too, all OK.
I started the service, and got NO error message, hum strange. I believe all tables are OK now, because everytime \ I do a mysqlcheck they all come back as OK.
Zabbix and mysql are working fine now!