I have been happily using the 2.6.21.6-grsec kernel with my debian etch machine, and yesterday I updated the kernel with a 2.6.23.1 using the latest grsec patch from October 12th, and since I rebooted I am experiencing a strange problem where the MySQL server would go down. It did four times in the past 24 hours (since I rebooted). This never happened before.
MySQL is version 5.0.32-7etch1, and as the version implies, it's running on a Debian Etch machine (32 bit). The kernel configuration basically remained the same.
In the syslog I can see this:
- Code: Select all
Oct 29 14:41:29 fonzie mysqld[5206]: Version: '5.0.32-Debian_7etch1-log' socket: '/var/run/mysqld/mysqld.sock' port: 3306 Debian etch distribution
Oct 29 17:13:39 fonzie kernel: grsec: signal 11 sent to /usr/sbin/mysqld[mysqld:19691] uid/euid:103/103 gid/egid:105/105, parent /usr/bin/mysqld_safe[mysqld_safe:1650] uid/euid:0/0 gid/egid:0/0
Oct 29 17:13:39 fonzie mysqld[5206]: mysqld got signal 11;
Oct 29 17:13:39 fonzie mysqld[5206]: This could be because you hit a bug. It is also possible that this binary
Oct 29 17:13:39 fonzie mysqld[5206]: or one of the libraries it was linked against is corrupt, improperly built,
Oct 29 17:13:39 fonzie mysqld[5206]: or misconfigured. This error can also be caused by malfunctioning hardware.
Oct 29 17:13:39 fonzie mysqld[5206]: We will try our best to scrape up some info that will hopefully help diagnose
Oct 29 17:13:39 fonzie mysqld[5206]: the problem, but since we have already crashed, something is definitely wrong
Oct 29 17:13:39 fonzie mysqld[5206]: and this may fail.
Oct 29 17:13:39 fonzie mysqld[5206]:
Oct 29 17:13:39 fonzie mysqld[5206]: key_buffer_size=16777216
Oct 29 17:13:39 fonzie mysqld[5206]: read_buffer_size=131072
Oct 29 17:13:39 fonzie mysqld[5206]: max_used_connections=13
Oct 29 17:13:39 fonzie mysqld[5206]: max_connections=100
Oct 29 17:13:39 fonzie mysqld[5206]: threads_connected=4
Oct 29 17:13:39 fonzie mysqld[5206]: It is possible that mysqld could use up to
Oct 29 17:13:39 fonzie mysqld[5206]: key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 233983 K
Oct 29 17:13:39 fonzie mysqld[5206]: bytes of memory
Oct 29 17:13:39 fonzie mysqld[5206]: Hope that's ok; if not, decrease some variables in the equation.
Oct 29 17:13:39 fonzie mysqld[5206]:
Oct 29 17:13:39 fonzie mysqld[5206]: thd=0x8c63e08
Oct 29 17:13:39 fonzie mysqld[5206]: Attempting backtrace. You can use the following information to find out
Oct 29 17:13:39 fonzie mysqld[5206]: where mysqld died. If you see no messages after this, something went
Oct 29 17:13:39 fonzie mysqld[5206]: terribly wrong...
Oct 29 17:13:39 fonzie mysqld[5206]: Cannot determine thread, fp=0xb40a5b18, backtrace may not be correct.
Oct 29 17:13:39 fonzie mysqld[5206]: Stack range sanity check OK, backtrace follows:
Oct 29 17:13:39 fonzie mysqld[5206]: 0x81c0659
Oct 29 17:13:39 fonzie mysqld[5206]: 0x847a75a
Oct 29 17:13:39 fonzie mysqld[5206]: 0x847a591
Oct 29 17:13:39 fonzie mysqld[5206]: 0x82705e1
Oct 29 17:13:39 fonzie mysqld[5206]: 0x821424b
Oct 29 17:13:39 fonzie mysqld[5206]: 0x8209e85
Oct 29 17:13:39 fonzie mysqld[5206]: 0x820fc37
Oct 29 17:13:39 fonzie mysqld[5206]: 0x8209e85
Oct 29 17:13:39 fonzie mysqld[5206]: 0x820fc37
Oct 29 17:13:39 fonzie mysqld[5206]: 0x8213997
Oct 29 17:13:39 fonzie mysqld[5206]: 0x821fefd
Oct 29 17:13:39 fonzie mysqld[5206]: 0x8221c20
Oct 29 17:13:39 fonzie mysqld[5206]: 0x822248e
Oct 29 17:13:39 fonzie mysqld[5206]: 0x81d74a5
Oct 29 17:13:39 fonzie mysqld[5206]: 0x81dba17
Oct 29 17:13:39 fonzie mysqld[5206]: 0x81dbed0
Oct 29 17:13:39 fonzie mysqld[5206]: 0x81dd198
Oct 29 17:13:39 fonzie mysqld[5206]: 0x81ddba4
Oct 29 17:13:39 fonzie mysqld[5206]: 0xb7f86240
Oct 29 17:13:39 fonzie mysqld[5206]: 0xb7dc14ae
Oct 29 17:13:39 fonzie mysqld[5206]: New value of fp=(nil) failed sanity check, terminating stack trace!
Oct 29 17:13:39 fonzie mysqld[5206]: Please read http://dev.mysql.com/doc/mysql/en/using-stack-trace.html and follow instructions on how to resolve the stack trace. Resolved
Oct 29 17:13:39 fonzie mysqld[5206]: stack trace is much more helpful in diagnosing the problem, so please do
Oct 29 17:13:39 fonzie mysqld[5206]: resolve it
Oct 29 17:13:39 fonzie mysqld[5206]: Trying to get some variables.
Oct 29 17:13:39 fonzie mysqld[5206]: Some pointers may be invalid and cause the dump to abort...
Oct 29 17:13:39 fonzie mysqld[5206]: thd->query at 0x8beced0 = SELECT a.aid, count( p.pid ) AS pic_count, max( p.pid ) AS last_pid, max( p.ctime ) AS last_upload, a.keyword FROM cpg140_albums AS a LEFT JOIN cpg140_pictures AS p ON a.aid = p.aid AND p.approved = 'YES' WHERE a.aid IN (23, 24, 1, 2, 3, 37, 5, 6, 7, 8, 9, 25)GROUP BY a.aid
Oct 29 17:13:39 fonzie mysqld[5206]: thd->thread_id=6614
Oct 29 17:13:39 fonzie mysqld[5206]: The manual page at http://www.mysql.com/doc/en/Crashing.html contains
Oct 29 17:13:39 fonzie mysqld[5206]: information that should help you find out what is causing the crash.
Oct 29 17:13:39 fonzie mysqld_safe[23338]: Number of processes running now: 0
Oct 29 17:13:39 fonzie mysqld_safe[23340]: restarted
Oct 29 17:13:39 fonzie mysqld[23343]: 071029 17:13:39 InnoDB: Database was not shut down normally!
Oct 29 17:13:39 fonzie mysqld[23343]: InnoDB: Starting crash recovery.
Oct 29 17:13:39 fonzie mysqld[23343]: InnoDB: Reading tablespace information from the .ibd files...
Oct 29 17:13:39 fonzie mysqld[23343]: InnoDB: Restoring possible half-written data pages from the doublewrite
Oct 29 17:13:39 fonzie mysqld[23343]: InnoDB: buffer...
Oct 29 17:13:39 fonzie mysqld[23343]: 071029 17:13:39 InnoDB: Starting log scan based on checkpoint at
Oct 29 17:13:39 fonzie mysqld[23343]: InnoDB: log sequence number 0 1501827680.
Oct 29 17:13:39 fonzie mysqld[23343]: InnoDB: Doing recovery: scanned up to log sequence number 0 1501827680
Oct 29 17:13:39 fonzie mysqld[23343]: InnoDB: Last MySQL binlog file position 0 1885978, file name /var/log/mysql/mysql-bin.000453
Oct 29 17:13:39 fonzie mysqld[23343]: 071029 17:13:39 InnoDB: Started; log sequence number 0 1501827680
Oct 29 17:13:39 fonzie mysqld[23343]: 071029 17:13:39 [Note] Recovering after a crash using /var/log/mysql/mysql-bin
Oct 29 17:13:39 fonzie mysqld[23343]: 071029 17:13:39 [Note] Starting crash recovery...
Oct 29 17:13:39 fonzie mysqld[23343]: 071029 17:13:39 [Note] Crash recovery finished.
Oct 29 17:13:39 fonzie mysqld[23343]: 071029 17:13:39 [Note] /usr/sbin/mysqld: ready for connections.
Oct 29 17:13:39 fonzie mysqld[23343]: Version: '5.0.32-Debian_7etch1-log' socket: '/var/run/mysqld/mysqld.sock' port: 3306 Debian etch distribution
Oct 29 18:45:15 fonzie mysqld[23343]: 071029 18:45:15 [ERROR] /usr/sbin/mysqld: Incorrect key file for table './mysql52dccf90644ba2722815ebe5811/phpbb_search_wordmatch.MYI'; try to repair it
Oct 29 18:50:22 fonzie mysqld[23343]: ^G/usr/sbin/mysqld: Out of memory (Needed 5276 bytes)
Oct 29 18:50:22 fonzie relaylock: /var/qmail/bin/relaylock: Unable to connect to the mysql database, relay will work in closed mode & white list will not work
Oct 29 18:50:22 fonzie mysqld_safe[1639]: Number of processes running now: 0
Oct 29 18:50:22 fonzie mysqld_safe[1641]: restarted
Oct 29 18:50:22 fonzie mysqld[1644]: 071029 18:50:22 InnoDB: Database was not shut down normally!
Oct 29 18:50:22 fonzie mysqld[1644]: InnoDB: Starting crash recovery.
Oct 29 18:50:22 fonzie mysqld[1644]: InnoDB: Reading tablespace information from the .ibd files...
Oct 29 18:50:23 fonzie mysqld[1644]: InnoDB: Restoring possible half-written data pages from the doublewrite
Oct 29 18:50:23 fonzie mysqld[1644]: InnoDB: buffer...
Oct 29 18:50:23 fonzie mysqld[1644]: 071029 18:50:23 InnoDB: Starting log scan based on checkpoint at
Oct 29 18:50:23 fonzie mysqld[1644]: InnoDB: log sequence number 0 1501827700.
Oct 29 18:50:23 fonzie mysqld[1644]: InnoDB: Doing recovery: scanned up to log sequence number 0 1501827700
Oct 29 18:50:23 fonzie mysqld[1644]: InnoDB: Last MySQL binlog file position 0 1885978, file name /var/log/mysql/mysql-bin.000453
Oct 29 18:50:23 fonzie mysqld[1644]: 071029 18:50:23 InnoDB: Started; log sequence number 0 1501827700
Oct 29 18:50:23 fonzie mysqld[1644]: 071029 18:50:23 [Note] Recovering after a crash using /var/log/mysql/mysql-bin
Oct 29 18:50:23 fonzie mysqld[1644]: 071029 18:50:23 [Note] Starting crash recovery...
Oct 29 18:50:23 fonzie mysqld[1644]: 071029 18:50:23 [Note] Crash recovery finished.
Oct 29 18:50:23 fonzie mysqld[1644]: 071029 18:50:23 [Note] /usr/sbin/mysqld: ready for connections.
Oct 29 18:50:23 fonzie mysqld[1644]: Version: '5.0.32-Debian_7etch1-log' socket: '/var/run/mysqld/mysqld.sock' port: 3306 Debian etch distribution
Oct 29 21:44:51 fonzie mysqld[1644]: 071029 21:44:51 [ERROR] /usr/sbin/mysqld: Table './mysql52dccf90644ba2722815ebe5811/phpbb_search_wordmatch' is marked as crashed and should be repaired
Oct 29 21:44:51 fonzie mysqld[1644]: 071029 21:44:51 [ERROR] /usr/sbin/mysqld: Table './mysql52dccf90644ba2722815ebe5811/phpbb_search_wordmatch' is marked as crashed and should be repaired
Oct 29 21:56:49 fonzie mysqld[1644]: ^G/usr/sbin/mysqld: Out of memory (Needed 5276 bytes)
Oct 29 21:56:50 fonzie mysqld_safe[15947]: Number of processes running now: 0
Oct 29 21:56:50 fonzie mysqld_safe[15949]: restarted
Oct 29 21:56:50 fonzie mysqld[15952]: 071029 21:56:50 InnoDB: Database was not shut down normally!
Oct 29 21:56:50 fonzie mysqld[15952]: InnoDB: Starting crash recovery.
Oct 29 21:56:50 fonzie mysqld[15952]: InnoDB: Reading tablespace information from the .ibd files...
Oct 29 21:56:50 fonzie relaylock: /var/qmail/bin/relaylock: Unable to connect to the mysql database, relay will work in closed mode & white list will not work
Oct 29 21:56:50 fonzie mysqld[15952]: InnoDB: Restoring possible half-written data pages from the doublewrite
Oct 29 21:56:50 fonzie mysqld[15952]: InnoDB: buffer...
Oct 29 21:56:50 fonzie mysqld[15952]: 071029 21:56:50 InnoDB: Starting log scan based on checkpoint at
Oct 29 21:56:50 fonzie mysqld[15952]: InnoDB: log sequence number 0 1501827720.
Oct 29 21:56:50 fonzie mysqld[15952]: InnoDB: Doing recovery: scanned up to log sequence number 0 1501827720
Oct 29 21:56:50 fonzie mysqld[15952]: InnoDB: Last MySQL binlog file position 0 1885978, file name /var/log/mysql/mysql-bin.000453
Oct 29 21:56:50 fonzie mysqld[15952]: 071029 21:56:50 InnoDB: Started; log sequence number 0 1501827720
Oct 29 21:56:50 fonzie mysqld[15952]: 071029 21:56:50 [Note] Recovering after a crash using /var/log/mysql/mysql-bin
Oct 29 21:56:50 fonzie mysqld[15952]: 071029 21:56:50 [Note] Starting crash recovery...
Oct 29 21:56:50 fonzie mysqld[15952]: 071029 21:56:50 [Note] Crash recovery finished.
Oct 29 21:56:50 fonzie mysqld[15952]: 071029 21:56:50 [Note] /usr/sbin/mysqld: ready for connections.
Oct 29 21:56:50 fonzie mysqld[15952]: Version: '5.0.32-Debian_7etch1-log' socket: '/var/run/mysqld/mysqld.sock' port: 3306 Debian etch distribution
Oct 29 22:30:59 fonzie mysqld[15952]: 071029 22:30:59 [ERROR] /usr/sbin/mysqld: Table './mysql52dccf90644ba2722815ebe5811/phpbb_search_wordmatch' is marked as crashed and should be repaired
Oct 29 22:30:59 fonzie mysqld[15952]: 071029 22:30:59 [ERROR] /usr/sbin/mysqld: Table './mysql52dccf90644ba2722815ebe5811/phpbb_search_wordmatch' is marked as crashed and should be repaired
Oct 30 00:25:38 fonzie mysqld[15952]: 071030 0:25:38 [ERROR] /usr/sbin/mysqld: Table './mysql52dccf90644ba2722815ebe5811/phpbb_search_wordmatch' is marked as crashed and should be repaired
Oct 30 00:25:38 fonzie mysqld[15952]: 071030 0:25:38 [ERROR] /usr/sbin/mysqld: Table './mysql52dccf90644ba2722815ebe5811/phpbb_search_wordmatch' is marked as crashed and should be repaired
Any ideas?