crash at startup with corrupt innodb table

When trying to start a just-upgraded 10.1.8 server, the mysqld process crashes. I have traced this down to a specific InnoDB table, and found that innodb_force_recovery value of 1 does not allow the server to start, but 2 does. That combined with the logs seems to imply the crash s in the purge process.

I was able to recover this server by rolling back to 5.5.45 and dumping and re-importing the database that was having problems (dropping and recreating the table would have worked too I think, but I didn't know which table it was at the time). I now also believe I could have recovered by starting with innodb_force_recovery=2 and dumping the data and reimporting.

I know corrupt data happens, but my biggest problem (and biggest fear as we move forward upgrading customers) is that 5.5.45 could handle the broken table fine, as could 10.0.22. mysqlcheck and innochecksum didn't report any errors for the broken table. Opening this ticket in hopes that it will be fixed to be a non-crasher to be more confident in future upgrades.

I'm not 100% sure what version of MariaDB introduced this crash. I know 10.0.22 could handle the data and 10.1.4 crashed. I tried to bisect further back but I was getting download speeds of 15K/s and decided to leave it for later.

All of my testing was done with binaries from https://downloads.mariadb.org/mariadb/+releases/, specifically mariadb-5.5.45-linux-x86_64.tar.gz, mariadb-10.0.22-linux-x86_64.tar.gz, mariadb-10.1.4-linux-x86_64.tar.gz, and mariadb-10.1.8-linux-x86_64.tar.gz.

The database that was corrupt is Monolith.AuthSessions in this tar of mysql_data: broken table

Logs from crash:

2015-11-17 13:06:26 47512341515568 [Note] /opt/mysql/bin/mysqld (mysqld 10.1.8-MariaDB-log) starting as process 23384 ...
2015-11-17 13:06:26 47512341515568 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2015-11-17 13:06:26 47512341515568 [Note] InnoDB: The InnoDB memory heap is disabled
2015-11-17 13:06:26 47512341515568 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2015-11-17 13:06:26 47512341515568 [Note] InnoDB: Memory barrier is not used
2015-11-17 13:06:26 47512341515568 [Note] InnoDB: Compressed tables use zlib 1.2.3
2015-11-17 13:06:26 47512341515568 [Note] InnoDB: Using Linux native AIO
2015-11-17 13:06:26 47512341515568 [Note] InnoDB: Using CPU crc32 instructions
2015-11-17 13:06:26 47512341515568 [Note] InnoDB: Initializing buffer pool, size = 128.0M
2015-11-17 13:06:26 47512341515568 [Note] InnoDB: Completed initialization of buffer pool
2015-11-17 13:06:26 47512341515568 [Note] InnoDB: Highest supported file format is Barracuda.
2015-11-17 13:06:26 47512341515568 [Note] InnoDB: The log sequence numbers 1698223465 and 1698223465 in ibdata files do not match the log sequence number 1698223515 in the ib_logfiles!
2015-11-17 13:06:26 47512341515568 [Note] InnoDB: Database was not shutdown normally!
2015-11-17 13:06:26 47512341515568 [Note] InnoDB: Starting crash recovery.
2015-11-17 13:06:26 47512341515568 [Note] InnoDB: Reading tablespace information from the .ibd files...
2015-11-17 13:06:26 47512341515568 [Note] InnoDB: Restoring possible half-written data pages
2015-11-17 13:06:26 47512341515568 [Note] InnoDB: from the doublewrite buffer...
2015-11-17 13:06:27 47512341515568 [Note] InnoDB: 128 rollback segment(s) are active.
2015-11-17 13:06:27 2b3679806940 InnoDB: Assertion failure in thread 47512966687040 in file btr0cur.cc line 5341
InnoDB: Failing assertion: rb_ctx != RB_NONE
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.6/en/forcing-innodb-recovery.html
InnoDB: about forcing recovery.
151117 13:06:27 [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: 10.1.8-MariaDB-log
key_buffer_size=94371840
read_buffer_size=65536
max_used_connections=0
max_threads=102
thread_count=0
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 13470094 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 0x48000
2015-11-17 13:06:27 47512341515568 [Note] InnoDB: Waiting for purge to start
2015-11-17 13:06:27 47512341515568 [Note] InnoDB: Percona XtraDB (http://www.percona.com) 5.6.26-74.0 started; log sequence number 1698223515
2015-11-17 13:06:27 47512341515568 [Note] Plugin 'FEEDBACK' is disabled.
2015-11-17 13:06:27 47512341515568 [Note] Recovering after a crash using tc.log
2015-11-17 13:06:27 47512341515568 [Note] Starting crash recovery...
2015-11-17 13:06:27 47512341515568 [Note] Crash recovery finished.
2015-11-17 13:06:27 47512987666752 [Note] InnoDB: Dumping buffer pool(s) not yet started
2015-11-17 13:06:27 47512341515568 [Note] Server socket created on IP: '::'.
2015-11-17 13:06:27 47512341515568 [ERROR] Missing system table mysql.roles_mapping; please run mysql_upgrade to create it
2015-11-17 13:06:27 47512341515568 [Note] Event Scheduler: Loaded 0 events
2015-11-17 13:06:27 47513019758912 [Warning] Failed to load slave replication state from table mysql.gtid_slave_pos: 1146: Table 'mysql.gtid_slave_pos' doesn't exist
ERROR: 1146 Table 'Monolith.AutoIncrementResetTables' doesn't exist
2015-11-17 13:06:27 47512341515568 [Note] /opt/monolith/vendor/mysql/bin/mysqld: ready for connections.
Version: '10.1.8-MariaDB-log' socket: '/tmp/mysql.sock' port: 3306 MariaDB Server
mysys/stacktrace.c:247(my_print_stacktrace)[0xbf55be]
sql/signal_handler.cc:160(handle_fatal_signal)[0x75e6c4]
/lib64/libpthread.so.0[0x3a65a0eca0]
/lib64/libc.so.6(gsignal+0x35)[0x3a64e2ffc5]
/lib64/libc.so.6(abort+0x110)[0x3a64e31a70]
btr/btr0cur.cc:5470(btr_free_externally_stored_field(dict_index_t*, unsigned char*, unsigned char const*, unsigned long const*, page_zip_des_t*, unsigned long, trx_rb_ctx, mtr_t*))[0xa0e9d3]
row/row0purge.cc:712(row_purge_upd_exist_or_extern_func)[0x9ae60c]
que/que0que.cc:1089(que_thr_step)[0x979bd4]
trx/trx0purge.cc:1253(trx_purge(unsigned long, unsigned long, bool))[0x9dba74]
srv/srv0srv.cc:3434(srv_do_purge)[0x9c4507]
srv/srv0srv.cc:3618(srv_purge_coordinator_thread)[0x9ca5ca]
/lib64/libpthread.so.0[0x3a65a0683d]
/lib64/libc.so.6(clone+0x6d)[0x3a64ed4fdd]
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.
151117 13:06:27 mysqld_safe Number of processes running now: 0
151117 13:06:27 mysqld_safe mysqld restarted