Unexpected Database Errors

ting.mike

Member
So after a few months of smooth sailing with XenForo, this few days I've seen the forum went down a few times with the error message "An unexpected database error occurred. Please try again later."

I would reboot the server and it would go back up, only to have the same problem reoccurring after a few hours. Also during this period when the forum is online, sometimes trying to open certain threads return the same "An unexpected database error occurred. Please try again later."

Any clue what to look for?

 
Yes, you your host should be able to upgrade you (will usually require down time to reload the VPS to bring the new space allocation in), or you could have a look at what is using all the disc space and see if there is anything you can delete / recover.
 
Do you have an error log configured? Should be something in your my.cnf file like so:

log-error=/var/log/mysqld.error.log

If you do, what is being written to the error log when trying to start MySQL?
 
Do you have an error log configured? Should be something in your my.cnf file like so:

log-error=/var/log/mysqld.error.log

If you do, what is being written to the error log when trying to start MySQL?
Hi Matt,

I have just tried enabling the error log using this guide (below). Afterwards, trying to restart mysql yield another failed. I opened the log on /var/log/mysql.log and found only a blank file. I also noticed that while monitoring the folder /var/run/mysqld/ folder, the file mysqld.pid file would come and go with no apparent reason.

To debug applications which use a mysql database, it comes in handy to enable the query log to get all SQL queries that were sent to the database. Open the MySQL configuration file (my.cnf)
vi /etc/mysql/my.cnf
and add the line:
log=/var/log/mysql.log
in the [mysql] section of the file. Depending on the Linux distribution that you use, the my.cnf file can be /etc/my.cnf or /etc/mysql/my.cnf.
Afterwards restart mysql to apply the new the configuration:
/etc/init.d/mysql restart
 
Just got this error message when I tried starting mysql again:

root@www:/var/log# /etc/init.d/mysql start
Starting MySQL database server: mysqld . . . . . . . . . . . . . ..
Checking for corrupt, not cleanly closed and upgrade needing tables..
root@www:/var/log# ERROR 2013 (HY000): Lost connection to MySQL server at 'reading initial communication packet', system error: 0

Still nothing on the mysql.log file
 
Finally got some error logs on var/log/mysql/mysql.log:

-edit-

Tried to restarted it again and got the same error message (three times):

/usr/sbin/mysqld, Version: 5.1.63-0+squeeze1-log ((Debian)). started with:
Tcp port: 3306 Unix socket: /var/run/mysqld/mysqld.sock
Time Id Command Argument
/usr/sbin/mysqld, Version: 5.1.63-0+squeeze1-log ((Debian)). started with:
Tcp port: 3306 Unix socket: /var/run/mysqld/mysqld.sock
Time Id Command Argument
/usr/sbin/mysqld, Version: 5.1.63-0+squeeze1-log ((Debian)). started with:
Tcp port: 3306 Unix socket: /var/run/mysqld/mysqld.sock
Time Id Command Argument
 
On /var/log/syslog:

Dec 25 06:25:11 www rsyslogd: [origin software="rsyslogd" swVersion="4.6.4" x-pid="622" x-info="http://www.rsyslog.com"] rsysl$
Dec 25 06:25:13 www /USR/SBIN/CRON[23905]: (CRON) error (grandchild #23912 failed with exit status 1)
Dec 25 06:25:13 www /USR/SBIN/CRON[23905]: (CRON) info (No MTA installed, discarding output)
Dec 25 06:25:14 www mysqld_safe: Number of processes running now: 0
Dec 25 06:25:14 www mysqld_safe: mysqld restarted
Dec 25 06:25:14 www mysqld: 121225 6:25:14 [Note] Plugin 'FEDERATED' is disabled.
Dec 25 06:25:14 www mysqld: 121225 6:25:14 InnoDB: Initializing buffer pool, size = 8.0M
Dec 25 06:25:14 www mysqld: 121225 6:25:14 InnoDB: Completed initialization of buffer pool
Dec 25 06:25:14 www mysqld: InnoDB: The log sequence number in ibdata files does not match
Dec 25 06:25:14 www mysqld: InnoDB: the log sequence number in the ib_logfiles!
Dec 25 06:25:14 www mysqld: 121225 6:25:14 InnoDB: Database was not shut down normally!
Dec 25 06:25:14 www mysqld: InnoDB: Starting crash recovery.
Dec 25 06:25:14 www mysqld: InnoDB: Reading tablespace information from the .ibd files...
Dec 25 06:25:14 www mysqld: InnoDB: Restoring possible half-written data pages from the doublewrite
Dec 25 06:25:14 www mysqld: InnoDB: buffer...
Dec 25 06:25:14 www mysqld: 121225 6:25:14 InnoDB: ERROR: We were only able to scan the log up to
Dec 25 06:25:14 www mysqld: InnoDB: 0 620322816, but a checkpoint was at 0 620322958.
Dec 25 06:25:14 www mysqld: InnoDB: It is possible that the database is now corrupt!
Dec 25 06:25:14 www mysqld: 121225 6:25:14 InnoDB: Error: page 2837 log sequence number 0 620379562
Dec 25 06:25:14 www mysqld: InnoDB: is in the future! Current system log sequence number 0 620322958.
Dec 25 06:25:14 www mysqld: InnoDB: Your database may be corrupt or you may have copied the InnoDB
Dec 25 06:25:14 www mysqld: InnoDB: tablespace but not the InnoDB log files. See
Dec 25 06:25:14 www mysqld: InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-innodb-recovery.html
Dec 25 06:25:14 www mysqld: InnoDB: for more information.
Dec 25 06:25:14 www mysqld: 121225 6:25:14 InnoDB: Error: page 446720 log sequence number 0 620379870
Dec 25 06:25:14 www mysqld: InnoDB: is in the future! Current system log sequence number 0 620322958.
Dec 25 06:25:14 www mysqld: InnoDB: Your database may be corrupt or you may have copied the InnoDB
Dec 25 06:25:14 www mysqld: InnoDB: tablespace but not the InnoDB log files. See
Dec 25 06:25:14 www mysqld: InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-innodb-recovery.html
Dec 25 06:25:14 www mysqld: InnoDB: for more information.
Dec 25 06:25:14 www mysqld: InnoDB: 2 transaction(s) which must be rolled back or cleaned up
Dec 25 06:25:14 www mysqld: InnoDB: in total 1 row operations to undo
Dec 25 06:25:14 www mysqld: InnoDB: Trx id counter is 0 3519744
Dec 25 06:25:14 www mysqld: 121225 6:25:14 InnoDB: Error: page 0 log sequence number 0 620416774
Dec 25 06:25:14 www mysqld: InnoDB: is in the future! Current system log sequence number 0 620322958.
Dec 25 06:25:14 www mysqld: InnoDB: Your database may be corrupt or you may have copied the InnoDB
Dec 25 06:25:14 www mysqld: InnoDB: tablespace but not the InnoDB log files. See
Dec 25 06:25:14 www mysqld: InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-innodb-recovery.html
 
More errors upon calling the command mysqld:

root@www:~# mysqld
121225 10:14:31 [Note] Failed to execute my_stat on file '/var/log/mysql/mysql-bin.000001'
121225 10:14:31 [Note] Plugin 'FEDERATED' is disabled.
121225 10:14:31 InnoDB: Initializing buffer pool, size = 8.0M
121225 10:14:31 InnoDB: Completed initialization of buffer pool
InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
121225 10:14:31 InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files...
InnoDB: Restoring possible half-written data pages from the doublewrite
InnoDB: buffer...
121225 10:14:31 InnoDB: ERROR: We were only able to scan the log up to
InnoDB: 0 620322816, but a checkpoint was at 0 620322958.
InnoDB: It is possible that the database is now corrupt!
121225 10:14:31 InnoDB: Error: page 2837 log sequence number 0 620379562
InnoDB: is in the future! Current system log sequence number 0 620322958.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-innodb-recovery.html
InnoDB: for more information.
121225 10:14:31 InnoDB: Error: page 446720 log sequence number 0 620379870
InnoDB: is in the future! Current system log sequence number 0 620322958.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-innodb-recovery.html
InnoDB: for more information.
InnoDB: 2 transaction(s) which must be rolled back or cleaned up
InnoDB: in total 1 row operations to undo
InnoDB: Trx id counter is 0 3519744
121225 10:14:31 InnoDB: Error: page 0 log sequence number 0 620416774
InnoDB: is in the future! Current system log sequence number 0 620322958.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-innodb-recovery.html
InnoDB: for more information.
InnoDB: Starting in background the rollback of uncommitted transactions
121225 10:14:31 InnoDB: Rolling back trx with id 0 3519312, 1 rows to undo
121225 10:14:31 InnoDB: Started; log sequence number 0 620322958

InnoDB: Rolling back of trx id 0 3519312 completed
121225 10:14:31 InnoDB: Rolling back trx with id 0 3519272, 0 rows to undo
121225 10:14:31 InnoDB: Error: page 390555 log sequence number 0 620379942
InnoDB: is in the future! Current system log sequence number 0 620323144.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-innodb-recovery.html
InnoDB: for more information.
121225 10:14:31 InnoDB: Error: page 342 log sequence number 0 620416774
InnoDB: is in the future! Current system log sequence number 0 620323144.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-innodb-recovery.html
InnoDB: for more information.
121225 10:14:31 InnoDB: Error: page 442368 log sequence number 0 620683394
InnoDB: is in the future! Current system log sequence number 0 620323144.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-innodb-recovery.html
InnoDB: for more information.
InnoDB: Dump of the tablespace extent descriptor: len 40; hex 00000000000018cd0006c0000bb60006c0000b1600000001ffffffffffffffffffffffffffffffff; asc ;
InnoDB: Serious error! InnoDB is trying to free page 446720
InnoDB: though it is already marked as free in the tablespace!
InnoDB: The tablespace free space info is corrupt.
InnoDB: You may need to dump your InnoDB tables and recreate the whole
InnoDB: database!
InnoDB: Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
121225 10:14:31 InnoDB: Assertion failure in thread 140460301485824 in file ../../../storage/innobase/fsp/fsp0fsp.c line 3034
InnoDB: We intentionally generate a memory trap.
InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
InnoDB: If you get repeated assertion failures or crashes, even
InnoDB: immediately after the mysqld startup, there may be
InnoDB: corruption in the InnoDB tablespace. Please refer to
InnoDB: http://dev.mysql.com/doc/refman/5.1/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
10:14:31 UTC - mysqld got signal 6 ;
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=131072
max_used_connections=0
max_threads=151
thread_count=0
connection_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 346521 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0x0
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...
stack_bottom = 0 thread_stack 0x30000
mysqld(my_print_stacktrace+0x29) [0x7fbf7dcf7689]
mysqld(handle_fatal_signal+0x483) [0x7fbf7db0ba53]
/lib/libpthread.so.0(+0xeff0) [0x7fbf7d25dff0]
/lib/libc.so.6(gsignal+0x35) [0x7fbf7bd001b5]
/lib/libc.so.6(abort+0x180) [0x7fbf7bd02fc0]
mysqld(+0x56bd43) [0x7fbf7dbf6d43]
mysqld(+0x5eaab4) [0x7fbf7dc75ab4]
mysqld(trx_undo_truncate_end+0x3e4) [0x7fbf7dc77cb4]
mysqld(trx_roll_pop_top_rec_of_trx+0xc82) [0x7fbf7dc6dfb2]
mysqld(row_undo_step+0x2b4) [0x7fbf7dc50e54]
mysqld(que_run_threads+0x4fe) [0x7fbf7dc33e1e]
mysqld(trx_rollback_or_clean_all_without_sess+0x367) [0x7fbf7dc6cad7]
/lib/libpthread.so.0(+0x68ca) [0x7fbf7d2558ca]
/lib/libc.so.6(clone+0x6d) [0x7fbf7bd9db6d]
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
information that should help you find out what is causing the crash.
 
Top Bottom