Bug #29172 mysqld dumps at restore after Ubuntu upgrade
Submitted: 18 Jun 2007 10:01 Modified: 19 Jun 2007 11:43
Reporter: Fredrik Agert Email Updates:
Status: Can't repeat Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S1 (Critical)
Version:5.0.38 OS:Linux (2.6.17-10-generic #2 SMP Tue Dec 5 22:28:26 UTC 2006 i686 GNU/Linux)
Assigned to: Heikki Tuuri CPU Architecture:Any
Tags: Assertion failed in fil0fil.c line 3959, At CREATE TABLE

[18 Jun 2007 10:01] Fredrik Agert
Description:
The Mysql server and client is placed on the same ubuntu linux.
Connection via socks file (i think).
Unfortunately ubuntu 7.04 distributes mysqld without the symbols, so I cannot make a backtrace.

After a restart, mysqld did not start.
To get it starting at all i had to add

set-variable=innodb-force-recover=2 in my.cnf 

doing so I was able to drop broken the database.

Do you really want to drop the 'wikidb' database [y/N] y
mysqladmin: DROP DATABASE wikidb failed;
error: 'Unknown table 'blog_math''
root@agert:/usr/local/var# sudo rm wikidb/blog_math.frm

After that I removed the innodb-force-recover flag in my.cnf & restarted the mysql server.

I tried a restore

#mysql -u root -p < wikidb.2007-06-14.sql
Enter password:
ERROR 2013 (HY000) at line 427: Lost connection to MySQL server during query

I'm getting assertion failed during restore. I expected that the restore would work out.

The log output is 
=========================
fredrik@agert:~$ sudo mysqld
070618 11:49:43  InnoDB: Started; log sequence number 0 6515335
070618 11:49:43 [Note] mysqld: ready for connections.
Version: '5.0.38-Ubuntu_0ubuntu1-log'  socket: '/tmp/mysql.sock'  port: 3306  Ubuntu 7.04 distribution
InnoDB: Error: trying to access page number 4294957951 in space 0,
InnoDB: space name ./ibdata1,
InnoDB: which is outside the tablespace bounds.
InnoDB: Byte offset 0, len 16384, i/o type 10.
InnoDB: If you get this error at mysqld startup, please check that
InnoDB: your my.cnf matches the ibdata files that you have in the
InnoDB: MySQL server.
070618 11:51:22InnoDB: Assertion failure in thread 3018714000 in file fil0fil.c line 3959
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.0/en/forcing-recovery.html
InnoDB: about forcing recovery.
070618 11:51:22 - mysqld got signal 11;
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=1
max_connections=100
threads_connected=1
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_connections = 233983 K
bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

thd=0x8b01400
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...
Cannot determine thread, fp=0xb3edb1d8, backtrace may not be correct.
Stack range sanity check OK, backtrace follows:
0x81ea513
0x83dbf0f
0x83ba8b5
0x83baec6
0x83af0d6
0x83d52ba
0x83d384e
0x83d3c7e
0x83738de
0x832ae09
0x833e08f
0x835629c
0x82ad1d7
0x82ad8bf
0x829d9dc
0x8284e2a
0x82c43c2
0x8206055
0x82069c9
0x8206f27
0x82082b7
0x8208df0
0xb7ea631b
0xb7ccc57e
New value of fp=(nil) failed sanity check, terminating stack trace!
Please read http://dev.mysql.com/doc/mysql/en/using-stack-trace.html and follow instructions on how to resolve the stack trace. Resolved
stack trace is much more helpful in diagnosing the problem, so please do
resolve it
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort...
thd->query at 0x8b3a768 = CREATE TABLE `blog_page` (
  `page_id` int(8) unsigned NOT NULL auto_increment,
  `page_namespace` int(11) NOT NULL default '0',
  `page_title` varchar(255) character set latin1 collate latin1_bin NOT NULL default '',
  `page_restrictions` tinyblob NOT NULL,
  `page_counter` bigint(20) unsigned NOT NULL default '0',
  `page_is_redirect` tinyint(1) unsigned NOT NULL default '0',
  `page_is_new` tinyint(1) unsigned NOT NULL default '0',
  `page_random` double unsigned NOT NULL default '0',
  `page_touched` varchar(14) character set latin1 collate latin1_bin NOT NULL default '',
  `page_latest` int(8) unsigned NOT NULL default '0',
  `page_len` int(8) unsigned NOT NULL default '0',
  PRIMARY KEY  (`page_id`),
  UNIQUE KEY `name_title` (`page_namespace`,`page_title`),
  KEY `page_random` (`page_random`),
  KEY `page_len` (`page_len`)
) ENGINE=InnoDB DEFAULT CHARSET=latin1
thd->thread_id=2
The manual page at http://www.mysql.com/doc/en/Crashing.html contains
information that should help you find out what is causing the crash.
=============================
Unfortunately the Ubuntu distribution has removed the symbols from the executable, so I have difficulties creating a memory map.

How to repeat:
Edit my.cnf to add innodb-force-recover=2
start the server
#sudo mysql-server
drop the database with mysqladmin

#mysqladmin -u root --password=blah drop wikidb;
look for complaining output

#sudo rm /usr/local/var/wikidb/the-database-that-last-dumped.frm

Edit my.cnf to remove innodb-force-recover=2
make the restore with 

#mysql -u root -p < wikidb.2007-06-14.sql

mysql deamon dumps
[18 Jun 2007 10:34] Fredrik Agert
output from mysqlbinlog /var/log/mysql/mysql-bin.000265

Attachment: mysqlbinlog.txt (text/plain), 20.92 KiB.

[18 Jun 2007 10:35] Fredrik Agert
ls -l /usr/local/var

Attachment: ls.txt (text/plain), 575 bytes.

[18 Jun 2007 13:16] Heikki Tuuri
Fredrik,

what did you do at the mysqld restart? Do you have the .err file from earlier times?

InnoDB is apparently trying to access page -1 in the system tablespace!

Regards,

Heikki
[18 Jun 2007 13:53] Fredrik Agert
At the reboot I updated kernel to latest ubuntu official kernel.
After the reboot the mysqld did not start. The only logs I have is the
mysql-bin.[0-9]* logs, the mysql.err is empty and too old date.

#sudo killall mysqld
after the fored stop of mysqld i did 

# sudo rm wikidb/blog_math.frm

to remove the file that apparently not were in the log 

then i removed the 
innodb_force_recover=2 
variable in my.cnf to be able to update the tables.

I still have the mysql-bin.* files from the restart, attaching them to the error case
[18 Jun 2007 14:20] Heikki Tuuri
Fredrik,

but do you have the .err log of the mysqld server?

I am interested to see if it reported some corruption before you shut down the server.

Regards,

Heikki
[18 Jun 2007 14:51] Fredrik Agert
The only log I have mentioning mysqld is deamonlog.