Bug #88956 InnoDB: Trying to access page number which is outside the tablespace bounds
Submitted: 18 Dec 2017 11:50 Modified: 24 Dec 2017 13:36
Reporter: Aidan Diffey Email Updates:
Status: Duplicate Impact on me:
None 
Category:MySQL Server: InnoDB storage engine Severity:S2 (Serious)
Version:5.7.18 OS:Any (CentOS Linux release 7.4.1708 (Core))
Assigned to: CPU Architecture:Any
Tags: Centos 7, MySQL Server 5.7.18

[18 Dec 2017 11:50] Aidan Diffey
Description:

We are using MySQL 5.7.18 and we have hit an issue.

We have been storing data into the database successfully when a crash happened and we saw the following in our log file:

"
[ERROR] /usr/sbin/mysqld: The table '' is full
InnoDB: Assertion failure in thread 3397184320 in file os0file.cc line 1697
InnoDB: Failing assertion: offset > 0
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.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
00:59:13 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.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.

key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=69
max_threads=2000
thread_count=66
connection_count=65
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 794067 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
"

When the server restart we then see:

"
[ERROR] InnoDB: Trying to access page number 323040 in space 1039, space name <> which is outside the tablespace bounds. Byte offset 0, len 16384, i/o type read. If you get this error at mysqld startup, please check that your my.cnf matches the ibdata files that you have in the MySQL server.
" 

How to repeat:
Once MySQL is installed, add some data (preferably with BLOB data) to make a single .idb file > 5GB in size.  We are seeing the database crash and the recovery not complete.
[18 Dec 2017 13:23] Sinisa Milivojevic
Hi!

Thank you for your bug report.

First of all, what you did not mention is that it is a compressed InnoDB table, as this assertion can only occur with it.

Second, I have attempted your suggested test case and had no problems what so ever. Hence ....

There are several things you can do.

Please, continue running your operations on the compressed InnoDB tables and let us know if the assert happens again. But, do keep in mind that it has to be the exactly same assert, in the same file and in the same line. If you can not repeat exactly same assert then it is some problems with hardware, including the faulty disk controller, faulty hard disk ( or SSD), faulty RAM. It could even be a glitch in the RAM, that happens due to low quality RAM modules. If you are not using DDR4 ECC RAM, then it is quite possible.

Last, but not least do check whether you have not run out of the free space on that disk partition or out of the space in the tablespace itself.

Do let us know your feedback.
[18 Dec 2017 14:35] Aidan Diffey
Hello Sinisa Milivojevic.

We will run the test again but I can assure you that the hardware is not an issue as we have tried this on 3 separate environment, one of which was a brand new HP setup.

The only thing that I can think of hardware wise is that they are all running on a virtual infrastructure (ESXI) and not physical hardware.  Are there any known issues with this setup?

Additionally, do you have any advise on how to recover the MySQL instance without an un-install and re-install?

Regards
[18 Dec 2017 14:46] Sinisa Milivojevic
Hi!

It could be that your problems are caused by virtual infrastructure (ESXI). Can you let me know more about it ???

Best recovery is from the backup.

Also, get answers to other of my questions, please .....
[18 Dec 2017 21:14] Aidan Diffey
Hello Sinisa Milivojevic.

I have installed MySQL 5.7.18 onto my machine and have written a simple program that attempts to insert 100,000 rows into a table (containing zip data) and when my file size reaches 4.1GB I get the error:

"2017-12-18T21:03:47.471884Z 20 [ERROR] /usr/sbin/mysqld: The table '' is full"

Using my test program the server doesn't crash however it will not restart as I get the error:

"2017-12-18T21:07:22.413666Z 4 [ERROR] InnoDB: Trying to access page number 2705 in space 254, space name '', which is outside the tablespace bounds. Byte offset 0, len 16384, i/o type read. If you get this error at mysqld startup, please check that your my.cnf matches the ibdata files that you have in the MySQL server.
"

On my machine I get no assertion error.

Would the compression be causing an issue?
[18 Dec 2017 22:14] Aidan Diffey
Hello.

After some more investigation I can make the same assert error occur.  The way that I do this is:

1. Fill a table up and get the error "2017-12-18T22:07:34.779477Z 7 [ERROR] /usr/sbin/mysqld: The table '' is full"
2. Stop my client
3. Restart the client

After a few more "The table is full" error I see the following in the log file:

"
2017-12-18 22:08:58 0xde5ffb40  InnoDB: Assertion failure in thread 3730832192 in file os0file.cc line 1697
InnoDB: Failing assertion: offset > 0
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.7/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
22:08:58 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.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.

key_buffer_size=8388608
read_buffer_size=131072
max_used_connections=2
max_threads=1000
thread_count=3
connection_count=2
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 401129 K  bytes of memory
Hope that's ok; if not, decrease some variables in the equation.

Thread pointer: 0xd0312fb8
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 = de5ff2e0 thread_stack 0x30000
/usr/sbin/mysqld(my_print_stacktrace+0x41)[0x8b5a691]
/usr/sbin/mysqld(handle_fatal_signal+0x47a)[0x83b0b9a]
[0xf778d400]
[0xf778d430]
/lib/libc.so.6(gsignal+0x47)[0xf740f2d7]
/lib/libc.so.6(abort+0x143)[0xf7410b13]
/usr/sbin/mysqld[0x837ab07]
/usr/sbin/mysqld[0x8c2f872]
/usr/sbin/mysqld[0x8c2fe9f]
/usr/sbin/mysqld[0x8c2ffe8]
/usr/sbin/mysqld[0x8c301c4]
/usr/sbin/mysqld(_Z17os_file_read_funcR9IORequestiPvym+0x44)[0x8c305b4]
/usr/sbin/mysqld(_Z11os_aio_funcR9IORequestmPKc13pfs_os_file_tPvymbP10fil_node_tS4_+0x1b6)[0x8c313b6]
/usr/sbin/mysqld(_Z6fil_ioRK9IORequestbRK9page_id_tRK11page_size_tmmPvS8_+0x7b5)[0x8e32195]
/usr/sbin/mysqld[0x8dd4e5d]
/usr/sbin/mysqld(_Z13buf_read_pageRK9page_id_tRK11page_size_t+0x5f)[0x8dd680f]
/usr/sbin/mysqld(_Z16buf_page_get_genRK9page_id_tRK11page_size_tmP11buf_block_tmPKcmP5mtr_tb+0x3e6)[0x8da11e6]
/usr/sbin/mysqld[0x8e3fe58]
/usr/sbin/mysqld(_Z28fseg_alloc_free_page_generalPhmhmP5mtr_tS1_+0x266)[0x8e42106]
/usr/sbin/mysqld(_Z14btr_page_allocP12dict_index_tmhmP5mtr_tS2_+0x80)[0x8d664e0]
/usr/sbin/mysqld(_Z31btr_store_big_rec_extern_fieldsP10btr_pcur_tPK5upd_tPmPK9big_rec_tP5mtr_t7blob_op+0x684)[0x8d81044]
/usr/sbin/mysqld(_Z32row_ins_index_entry_big_rec_funcPK8dtuple_tPK9big_rec_tPmPP16mem_block_info_tP12dict_index_tPKcm+0x27e)[0x8c8119e]
/usr/sbin/mysqld(_Z29row_ins_clust_index_entry_lowmmP12dict_index_tmP8dtuple_tmP9que_thr_tb+0x35d)[0x8c86d2d]
/usr/sbin/mysqld(_Z25row_ins_clust_index_entryP12dict_index_tP8dtuple_tP9que_thr_tmb+0x15f)[0x8c8826f]
/usr/sbin/mysqld(_Z12row_ins_stepP9que_thr_t+0x332)[0x8c88682]
/usr/sbin/mysqld[0x8c9beff]
/usr/sbin/mysqld(_ZN11ha_innobase9write_rowEPh+0x22e)[0x8ba73ce]
/usr/sbin/mysqld(_ZN7handler12ha_write_rowEPh+0x193)[0x840bc63]
/usr/sbin/mysqld(_Z12write_recordP3THDP5TABLEP9COPY_INFOS4_+0xd3)[0x8a90763]
/usr/sbin/mysqld(_ZN14Sql_cmd_insert12mysql_insertEP3THDP10TABLE_LIST+0x976)[0x8a923e6]
/usr/sbin/mysqld(_ZN14Sql_cmd_insert7executeEP3THD+0xf0)[0x8a92da0]
/usr/sbin/mysqld(_Z21mysql_execute_commandP3THDb+0x945)[0x88ef8d5]
/usr/sbin/mysqld(_Z11mysql_parseP3THDP12Parser_state+0x460)[0x88f7190]
/usr/sbin/mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0xd4f)[0x88f7f4f]
/usr/sbin/mysqld(_Z10do_commandP3THD+0x1a0)[0x88f9d80]
/usr/sbin/mysqld(handle_connection+0x2c0)[0x89cab00]
/usr/sbin/mysqld(pfs_spawn_thread+0x1e3)[0x8f276f3]
/lib/libpthread.so.0(+0x6b2c)[0xf773db2c]
/lib/libc.so.6(clone+0x5e)[0xf74d917e]

Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (d0343b18): Can't read from address d0343b18
Connection ID (thread ID): 8
Status: NOT_KILLED

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.
2017-12-18T22:09:00.000848Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2017-12-18T22:09:00.000869Z 0 [Warning] 'NO_ZERO_DATE', 'NO_ZERO_IN_DATE' and 'ERROR_FOR_DIVISION_BY_ZERO' sql modes should be used with strict mode. They will be merged with strict mode in a future release.
2017-12-18T22:09:00.001925Z 0 [Note] /usr/sbin/mysqld (mysqld 5.7.18) starting as process 9133 ...
2017-12-18T22:09:00.005007Z 0 [Note] InnoDB: PUNCH HOLE support available
2017-12-18T22:09:00.005018Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-12-18T22:09:00.005023Z 0 [Note] InnoDB: Uses event mutexes
2017-12-18T22:09:00.005044Z 0 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-12-18T22:09:00.005047Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3
2017-12-18T22:09:00.005050Z 0 [Note] InnoDB: Using Linux native AIO
2017-12-18T22:09:00.005349Z 0 [Note] InnoDB: Number of pools: 1
2017-12-18T22:09:00.005439Z 0 [Note] InnoDB: Not using CPU crc32 instructions
2017-12-18T22:09:00.006462Z 0 [Note] InnoDB: Initializing buffer pool, total size = 128M, instances = 1, chunk size = 128M
2017-12-18T22:09:00.011710Z 0 [Note] InnoDB: Completed initialization of buffer pool
2017-12-18T22:09:00.012770Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2017-12-18T22:09:00.024408Z 0 [Note] InnoDB: Highest supported file format is Barracuda.
2017-12-18T22:09:00.024932Z 0 [Note] InnoDB: Log scan progressed past the checkpoint lsn 17934411811
2017-12-18T22:09:00.028398Z 0 [Note] InnoDB: Doing recovery: scanned up to log sequence number 17935586907
2017-12-18T22:09:00.028531Z 0 [Note] InnoDB: Database was not shutdown normally!
2017-12-18T22:09:00.028536Z 0 [Note] InnoDB: Starting crash recovery.
"
[19 Dec 2017 17:52] Sinisa Milivojevic
Hi!

What do you mean by "table containing zip data" ???? What is "zip data" ????

I suppose you are using BLOB for the purpose ...... do you use compressed option for the row or not ???

What command did you exactly run when you have got that assert ???

I asked you many other questions, among other to check whether you are running into some quota limit or disk partition limt ????

Also, you could be running into the virtual hardware limit. When using virtual environments, disk (and memory) sizes can be limited. You should check out that too.

Please, provide answers to all of these questions, before we proceed .......
[19 Dec 2017 18:01] Aidan Diffey
Hello.

>> What do you mean by "table containing zip data" ???? What is "zip data" ????
The table that is getting full is a table that contains BLOB data. The schema is:

+-------------+------------------+------+-----+---------+-------+
| Field       | Type             | Null | Key | Default | Extra |
+-------------+------------------+------+-----+---------+-------+
| ID          | varchar(30)      | NO   | PRI | NULL    |       |
| MESSAGE     | mediumblob       | YES  |     | NULL    |       |
| XMLTEXTMODE | char(1)          | YES  |     | NULL    |       |
| CHECK_SUM   | int(10) unsigned | NO   |     | NULL    |       |
+-------------+------------------+------+-----+---------+-------+
4 rows in set (0.00 sec)

>> I suppose you are using BLOB for the purpose ...... do you use compressed option for the row or not ???

The table is not created with compression on.

| test  | CREATE TABLE `test` (
  `ID` varchar(30) NOT NULL COMMENT 'reference to identifier',
  `MESSAGE` mediumblob,
  `XMLTEXTMODE` char(1) DEFAULT NULL COMMENT 'Storage type of data',
  `CHECK_SUM` int(10) unsigned NOT NULL COMMENT 'Checksum for blob',
  PRIMARY KEY (`ID`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8 |

>> What command did you exactly run when you have got that assert ???
I have a Java program which reads in a zip file from the disk as a byte[] and inserts it into the table in a loop.  The command is:

private static String SQL = "INSERT INTO mine.test VALUES (?,?,?,?)";

for (int i = 160000; i < 200000; i++) {
  PreparedStatement stmt = conn.prepareStatement(SQL);
    try {
	stmt.setString(1, String.format("N%d0000000", i));
	stmt.setBytes(2, file);
	stmt.setString(3, "Y");
	stmt.setInt(4, i);
	stmt.execute();
	} catch (Exception e) {
		// System.out.println(e.getMessage());
}
				finally
				{
					stmt.close();
				}
[19 Dec 2017 18:05] Sinisa Milivojevic
Hi!

We need the finally generated SQL statement and not the way that your Java program generates the query.

Also, I have asked so many other questions and we are waiting until you answer them.
[19 Dec 2017 18:09] Sinisa Milivojevic
Hi!

You can not change status to "Open" without providing the answers that we have asked for.
[19 Dec 2017 18:14] Aidan Diffey
Sorry for the double post.  Firefox didn't play well.

The final SQL is massive (as it contains byte data) so a cut down version is:

com.mysql.jdbc.JDBC42PreparedStatement@5876a9af: INSERT INTO mine.test VALUES ('N1600000000000',_binary'P','Y',160000)
[19 Dec 2017 20:33] Shane Bester
I'm going out on a limb to predict this problem is on a 32-bit mysqld and "offset" is defined as ulint which is incorrect type and wraps at 2^32...
[19 Dec 2017 20:38] Aidan Diffey
MySQL information:

mysql> show variables like 'version_compile_machine';
+-------------------------+-------+
| Variable_name           | Value |
+-------------------------+-------+
| version_compile_machine | i686  |
+-------------------------+-------+
1 row in set (0.01 sec)

mysql  Ver 14.14 Distrib 5.7.18, for Linux (i686) using  EditLine wrapper

Connection id:		72624
Current database:	
Current user:		root@localhost
SSL:			Not in use
Current pager:		stdout
Using outfile:		''
Using delimiter:	;
Server version:		5.7.18 MySQL Community Server (GPL)
Protocol version:	10
Connection:		Localhost via UNIX socket
Server characterset:	latin1
Db     characterset:	latin1
Client characterset:	utf8
Conn.  characterset:	utf8
UNIX socket:		/var/lib/mysql/mysql.sock
Uptime:			1 hour 12 min 53 sec

Threads: 2  Questions: 687449  Slow queries: 0  Opens: 155  Flush tables: 1  Open tables: 115  Queries per second avg: 157.203
--------------
[20 Dec 2017 14:42] Sinisa Milivojevic
Hi!

You can get whether this executable binary is 32-bit or 64-bit one by using Unix-wide shell utility for the purpose.

Another way of getting this info is the full name of that RPM or tarball file that you downloaded from our site.

You have also not answered other questions of ours, like the limits set in the virtual environment or on the physical partitions or with quotas. With virtual environments , limits can change during runtime and provoke a havoc.
[24 Dec 2017 13:32] Shane Bester
I can repeat this bug so am verifying it.  A duplicate of:

https://bugs.mysql.com/bug.php?id=87423
BUG 26636815 - OS0FILE.CC ASSERTION FAILED 'OFFSET > 0' IN OS_FILE_IO_COMPLETE

Please,  migrate your systems to 64-bit to avoid the bug.
Even MySQL 8.0 no longer has 32-bit binaries!!

Version: '5.7.20'  socket: ''  port: 3306  MySQL Community Server (GPL)
2017-12-24T13:32:29.238749Z 0 [Note] Executing 'SELECT * FROM INFORMATION_SCHEMA.TABLES;' to get a list of tables using the deprecated partition engine. You may use the startup option '--disable-partition-engine-check' to skip this check.
2017-12-24T13:32:29.239749Z 0 [Note] Beginning of list of non-natively partitioned tables
2017-12-24T13:32:29.284254Z 0 [Note] End of list of non-natively partitioned tables
2017-12-24T13:32:32.755195Z 3 [ERROR] InnoDB: Trying to access page number 3 in space 23, space name test/t, which is outside the tablespace bounds. Byte offset 0, len 16384, i/o type read. If you get this error at mysqld startup, please check that your my.cnf matches the ibdata files that you have in the MySQL server.
2017-12-24T13:32:32.756695Z 3 [ERROR] InnoDB: Server exits.

E:\mysql-5.7.20-win32\bin>