[MDEV-5887] Crash: page number outside the tablespace bounds Created: 2014-03-17  Updated: 2014-07-22  Resolved: 2014-07-22

Status: Closed
Project: MariaDB Server
Component/s: None
Affects Version/s: 5.5.35
Fix Version/s: 5.5.39

Type: Bug Priority: Major
Reporter: Nicolas Payart Assignee: Jan Lindström (Inactive)
Resolution: Not a Bug Votes: 0
Labels: None
Environment:
  • Server DELL PowerEdge 2950 32 GB RAM, 2 x Intel Xeon CPU E5420@2.50GHz
  • Linux Debian 7.4 (wheezy), ext4 filesystem
  • Defined as a MySQL Slave using MIXED binlog format


 Description   

I had a crash on a MariaDB 5.5.35 slave with the following error (see below).

I have not much information about what was running at this moment, but wonder if someone have some tips or any known issues regarding such error trace ("access page [...] is outside the tablespace bounds").

Don't know if it may be related but I noticed I had a quite large sort_buffer_size in my.cnf (16MB, restored to its default value since). I recreated the slave instance and did not reproduced the problem though.

140311 14:46:06 [Note] /usr/local/mysql/bin/mysqld: ready for connections.
 
Version: '5.5.35-MariaDB-log'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MariaDB Server
 
InnoDB: Error: trying to access page number 4294503295 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.
 
140311 14:47:31  InnoDB: Assertion failure in thread 140687496423168 in file fil0fil.c line 5462
 
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.5/en/forcing-innodb-recovery.html
 
InnoDB: about forcing recovery.
 
140311 14:47:31 [ERROR] 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.
 
 
 
To report this bug, see http://kb.askmonty.org/en/reporting-bugs
 
 
 
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.
 
 
 
Server version: 5.5.35-MariaDB-log
 
key_buffer_size=536870912
 
read_buffer_size=1048576
 
max_used_connections=19
 
max_threads=502
 
thread_count=2
 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 9272059 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x0x0
 
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 = 0x0 thread_stack 0x40000
 
mysys/stacktrace.c:247(my_print_stacktrace)[0xaed74e]
 
sql/signal_handler.cc:153(handle_fatal_signal)[0x6da40c]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0xf030)[0x7ff8feb9f030]
 
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x35)[0x7ff8fdc6b475]
 
/lib/x86_64-linux-gnu/libc.so.6(abort+0x180)[0x7ff8fdc6e6f0]
 
fil/fil0fil.c:5512(_fil_io)[0x9a4266]
 
buf/buf0rea.c:239(buf_read_page_low)[0x97a59f]
 
buf/buf0rea.c:455(buf_read_page)[0x97b7c9]
 
buf/buf0buf.c:2577(buf_page_get_gen)[0x967cf1]
 
include/fut0fut.ic:53(fut_get_ptr)[0x9bb8fb]
 
fsp/fsp0fsp.c:2044(fsp_free_seg_inode)[0x9af565]
 
fsp/fsp0fsp.c:3603(fseg_free_step)[0x9b6c18]
 
trx/trx0purge.c:493(trx_purge_free_segment)[0x9285ef]
 
trx/trx0purge.c:655(trx_purge_truncate_history)[0x92a16a]
 
row/row0purge.c:749(row_purge)[0xa0fd26]
 
que/que0que.c:1259(que_thr_step)[0xa0533c]
 
trx/trx0purge.c:1229(trx_purge)[0x928c8b]
 
srv/srv0srv.c:4192(srv_purge_thread)[0x91c4dc]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x6b50)[0x7ff8feb96b50]
 
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7ff8fdd150ed]
 
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.
 
140311 14:47:32 mysqld_safe Number of processes running now: 0
 
140311 14:47:32 mysqld_safe mysqld restarted
 
140311 14:47:32 InnoDB: The InnoDB memory heap is disabled
 
140311 14:47:32 InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
140311 14:47:32 InnoDB: Compressed tables use zlib 1.2.3
 
140311 14:47:32 InnoDB: Using Linux native AIO
 
140311 14:47:32 InnoDB: Initializing buffer pool, size = 16.0G
 
140311 14:47:34 InnoDB: Completed initialization of buffer pool
 
140311 14:47:34 InnoDB: highest supported file format is Barracuda.
 
InnoDB: The log sequence number in ibdata files does not match
 
InnoDB: the log sequence number in the ib_logfiles!
 
140311 14:47:34  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...
 
InnoDB: In a MySQL replication slave the last master binlog file
 
InnoDB: position 65074994, file name mysql-bin.001125
 
InnoDB: and relay log file
 
InnoDB: position 65075278, file name ./relay-bin.000245
 
InnoDB: Last MySQL binlog file position 0 4668, file name /data/inetlog/mysql/mysql-bin.000005
 
140311 14:47:35  InnoDB: Waiting for the background threads to start
 
140311 14:47:36 Percona XtraDB (http://www.percona.com) 5.5.35-MariaDB-33.0 started; log sequence number 865880510567
 
140311 14:47:36 [Note] Plugin 'FEEDBACK' is disabled.
 
140311 14:47:36 [Note] Recovering after a crash using /data/inetlog/mysql/mysql-bin
 
140311 14:47:36 [Note] Starting crash recovery...
 
140311 14:47:36 [Note] Crash recovery finished.
 
140311 14:47:36 [Note] Server socket created on IP: '0.0.0.0'.
 
140311 14:47:36 [Warning] 'user' entry 'root@maroc' ignored in --skip-name-resolve mode.
 
140311 14:47:36 [Warning] 'proxies_priv' entry '@ root@maroc' ignored in --skip-name-resolve mode.
 
140311 14:47:36 [Note] Event Scheduler: Loaded 0 events
 
140311 14:47:36 [Note] /usr/local/mysql/bin/mysqld: ready for connections.
 
Version: '5.5.35-MariaDB-log'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MariaDB Server
 
InnoDB: Error: trying to access page number 4294503295 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.
 
140311 14:49:04  InnoDB: Assertion failure in thread 139631139989248 in file fil0fil.c line 5462
 
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.5/en/forcing-innodb-recovery.html
 
InnoDB: about forcing recovery.
 
140311 14:49:04 [ERROR] 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.
 
 
 
To report this bug, see http://kb.askmonty.org/en/reporting-bugs
 
 
 
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.
 
 
 
Server version: 5.5.35-MariaDB-log
 
key_buffer_size=536870912
 
read_buffer_size=1048576
 
max_used_connections=16
 
max_threads=502
 
thread_count=5
 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 9272059 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0x0x0
 
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 = 0x0 thread_stack 0x40000
 
mysys/stacktrace.c:247(my_print_stacktrace)[0xaed74e]
 
sql/signal_handler.cc:153(handle_fatal_signal)[0x6da40c]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0xf030)[0x7f030aee5030]
 
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x35)[0x7f0309fb1475]
 
/lib/x86_64-linux-gnu/libc.so.6(abort+0x180)[0x7f0309fb46f0]
 
fil/fil0fil.c:5512(_fil_io)[0x9a4266]
 
buf/buf0rea.c:239(buf_read_page_low)[0x97a59f]
 
buf/buf0rea.c:455(buf_read_page)[0x97b7c9]
 
buf/buf0buf.c:2577(buf_page_get_gen)[0x967cf1]
 
include/fut0fut.ic:53(fut_get_ptr)[0x9bb8fb]
 
fsp/fsp0fsp.c:2044(fsp_free_seg_inode)[0x9af565]
 
fsp/fsp0fsp.c:3603(fseg_free_step)[0x9b6c18]
 
trx/trx0purge.c:493(trx_purge_free_segment)[0x9285ef]
 
trx/trx0purge.c:655(trx_purge_truncate_history)[0x92a16a]
 
row/row0purge.c:749(row_purge)[0xa0fd26]
 
que/que0que.c:1259(que_thr_step)[0xa0533c]
 
trx/trx0purge.c:1229(trx_purge)[0x928c8b]
 
srv/srv0srv.c:4192(srv_purge_thread)[0x91c4dc]
 
/lib/x86_64-linux-gnu/libpthread.so.0(+0x6b50)[0x7f030aedcb50]
 
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f030a05b0ed]
 
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.
 
140311 14:49:05 mysqld_safe Number of processes running now: 0
 
140311 14:49:05 mysqld_safe mysqld restarted
 
140311 14:49:05 InnoDB: The InnoDB memory heap is disabled
 
140311 14:49:05 InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
140311 14:49:05 InnoDB: Compressed tables use zlib 1.2.3
 
140311 14:49:05 InnoDB: Using Linux native AIO
 
140311 14:49:05 InnoDB: Initializing buffer pool, size = 16.0G
 
140311 14:49:07 InnoDB: Completed initialization of buffer pool
 
140311 14:49:07 InnoDB: highest supported file format is Barracuda.
 
InnoDB: The log sequence number in ibdata files does not match
 
InnoDB: the log sequence number in the ib_logfiles!
 
140311 14:49:07  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...
 
InnoDB: In a MySQL replication slave the last master binlog file
 
InnoDB: position 65074994, file name mysql-bin.001125
 
InnoDB: and relay log file
 
InnoDB: position 65075278, file name ./relay-bin.000245
 
InnoDB: Last MySQL binlog file position 0 4668, file name /data/inetlog/mysql/mysql-bin.000005
 
140311 14:49:08  InnoDB: Waiting for the background threads to start
 
140311 14:49:09 Percona XtraDB (http://www.percona.com) 5.5.35-MariaDB-33.0 started; log sequence number 865880510717
 
140311 14:49:09 [Note] Plugin 'FEEDBACK' is disabled.
 
140311 14:49:09 [Note] Recovering after a crash using /data/inetlog/mysql/mysql-bin
 
140311 14:49:09 [Note] Starting crash recovery...
 
140311 14:49:09 [Note] Crash recovery finished.
 
140311 14:49:09 [Note] Server socket created on IP: '0.0.0.0'.
 
140311 14:49:09 [Warning] 'user' entry 'root@maroc' ignored in --skip-name-resolve mode.
 
140311 14:49:09 [Warning] 'proxies_priv' entry '@ root@maroc' ignored in --skip-name-resolve mode.
 
140311 14:49:10 [Note] Event Scheduler: Loaded 0 events
 
140311 14:49:10 [Note] /usr/local/mysql/bin/mysqld: ready for connections.
 
Version: '5.5.35-MariaDB-log'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MariaDB Server



 Comments   
Comment by Elena Stepanova [ 2014-03-17 ]

Hi Nicolas,
What is the value of innodb_force_recovery in the server where you had the crashes?

Comment by Nicolas Payart [ 2014-03-17 ]

innodb_force_recovery was set to 0 (default).

We tried values from 1 to 3 without success (still crashing with innodb_force_recovery = 1 or 2 while server did not start with innodb_force_recovery = 3)

Comment by Elena Stepanova [ 2014-03-17 ]

Nicolas,

Was there any preceding story, e.g. you moved the datadir (or ib* files) from another machine, or modified config file, had disk/power problems, etc.?
Could you please attach your cnf file(s) and the complete error log, or at least the part from the last server start before the first time you observed the crash?

Thanks.

Comment by Nicolas Payart [ 2014-03-18 ]

Unfortunately the datadir has been removed (slave has been rebuilt from scratch).
The error log from my first post is the only log trace I have...

From what I know there have been no system modification in the hours/days preceding the crash, nor dell omsa alert. I just noticed this error message in dmesg (PERC 6/i controller):

[   31.640010] megaraid_sas 0000:01:00.0: vpd r/w failed.  This is likely a firmware bug on this device.  Contact the card vendor for a firmware update.

Here is my.cnf :

[client]
 
port		= 3306
 
socket		= /var/run/mysqld/mysqld.sock
 
 
 
 
 
# This was formally known as [safe_mysqld]. Both versions are currently parsed.
 
[mysqld_safe]
 
socket          = /var/run/mysqld/mysqld.sock
 
nice            = 0
 
 
 
 
 
# The MariaDB server
 
[mysqld]
 
#
 
# * Basic Settings
 
#
 
user            = mysql
 
port		= 3306
 
socket		= /var/run/mysqld/mysqld.sock
 
pid-file        = /var/run/mysqld/mysqld.pid
 
basedir         = /usr/local/mysql
 
datadir         = /data/inetbase/mysql
 
tmpdir          = /data/inetlog/mysql
 
lc-messages-dir = /usr/local/mysql/share
 
lc-messages     = en_US
 
skip-external-locking
 
skip-name-resolve
 
max_connections = 500
 
connect_timeout = 10
 
 
 
#
 
# * Fine Tuning
 
#
 
tmp_table_size          = 256M
 
max_heap_table_size     = 256M
 
max_allowed_packet      = 16M
 
table_open_cache        = 4096
 
table_definition_cache  = 2048
 
sort_buffer_size        = 16M
 
read_buffer_size        = 1M
 
read_rnd_buffer_size    = 2M
 
thread_cache_size       = 64
 
thread_concurrency      = 8
 
thread_stack            = 256K
 
table_cache             = 65534
 
open_files_limit        = 65000
 
optimizer_switch        = engine_condition_pushdown=on
 
 
 
 
 
#
 
# * MyISAM Tuning
 
#
 
key_buffer_size         = 512M
 
key_cache_segments      = 32
 
key_cache_block_size    = 4K
 
myisam_sort_buffer_size = 128M
 
myisam-recover          = BACKUP
 
 
 
#
 
# * InnoDB Tuning
 
#
 
innodb_file_per_table
 
innodb_buffer_pool_size        = 16G
 
innodb_buffer_pool_instances   = 4
 
innodb_flush_log_at_trx_commit = 2
 
innodb_log_file_size           = 1G
 
innodb_log_files_in_group      = 2
 
innodb_log_buffer_size         = 128M
 
innodb_io_capacity             = 400
 
innodb_max_dirty_pages_pct     = 25
 
innodb_support_xa              = 0
 
innodb_stats_update_need_lock  = 0
 
innodb_thread_concurrency      = 128
 
innodb_open_files              = 8192
 
 
 
#
 
# * Query Cache Configuration
 
#
 
query_cache_type = 0
 
query_cache_size = 0
 
 
 
#
 
# * Logging and Replication
 
#
 
read-only
 
server-id	  = 3122
 
binlog_format     = MIXED
 
binlog_cache_size = 10M
 
max_binlog_size   = 100M
 
log-bin           = /data/inetlog/mysql/mysql-bin.log
 
relay-log         = relay-bin
 
expire_logs_days  = 3
 
skip-slave-start
 
log-slow-slave-statements
 
general_log_file        = /data/inetlog/mysql/mysql.log
 
general-log             = 0
 
slow_query_log_file     = /data/inetlog/mysql/mysql-slow.log
 
slow-query-log          = 1
 
long_query_time         = 0.250
 
 
 
[mysqldump]
 
quick
 
max_allowed_packet = 16M
 
 
 
 
 
[myisamchk]
 
key_buffer_size = 128M
 
sort_buffer_size = 128M
 
read_buffer = 2M
 
write_buffer = 2M
 
 
 
 
 
[mysqlhotcopy]
 
interactive-timeout

Comment by Elena Stepanova [ 2014-05-22 ]

Passing it to jplindst to see if it looks any familiar.

Comment by Jan Lindström (Inactive) [ 2014-07-22 ]

Possible reason: hw error. Please reopen if repeatable with 5.5.39.

Generated at Thu Feb 08 07:07:47 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.