Bug #65338 InnoDB assertion: unable to decompress space
Submitted: 16 May 2012 18:29 Modified: 5 Jun 2012 16:19
Reporter: Davi Arnaut (OCA) Email Updates:
Status: Can't repeat Impact on me:
Category:MySQL Server: InnoDB storage engine Severity:S3 (Non-critical)
Version:5.5.23, 5.6.6-m9 OS:Any
Assigned to: CPU Architecture:Any
Tags: assertion, compression, innodb, varchar

[16 May 2012 18:29] Davi Arnaut
The RQG test grammar engine/varchar.yy can repeatedly trigger a InnoDB assertion when table compression is enabled.

Assertion message:

InnoDB: unable to decompress space 8 page 1737
InnoDB: Assertion failure in thread 1082779968 in file buf0buf.cc line 2684
InnoDB: Failing assertion: buf_zip_decompress(block, TRUE)

Crash recovery also fails:

InnoDB: Doing recovery: scanned up to log sequence number 2605600195
120516 21:18:50  InnoDB: Starting an apply batch of log records to the database...
InnoDB: Progress in percents: 0 1 2 3 4 5 [...] 56 57 $
InnoDB: Database page corruption on disk or a failed
InnoDB: file read of page 3026.
InnoDB: You may have to recover from a backup.
120516 21:18:50 InnoDB: Page dump in ascii and hex (8192 bytes):
 len 8192; hex 90e07e5e00000bd2ffffffff00000bd3000000009b26d62245bf000000000000000000000 [...]
InnoDB: End of page dump
InnoDB: Compressed page type (17855); stored checksum in field1 2430631518; calculated checksums for field1: crc32 4120080821, innodb 2430631518, none 3735928559; page LSN 260301$
InnoDB: Page may be an update undo log page
InnoDB: Page may be an index page where index id is 22
InnoDB: Database page corruption on disk or a failed                                    
InnoDB: file read of page 3026.

How to repeat:
Ensure that the InnoDB file format is Barracuda and that per-table tablespaces is enabled.

RQG command:

perl /gentest.pl \
--dsn=dbi:mysql:host= \
--gendata=conf/engines/varchar.zz --grammar=conf/engines/varchar.yy \
--reporter=Backtrace,ErrorLog --engine=InnoDB \
--queries=1M --rows=10000 --seed=time --duration=600

Patch to enable table compression:

=== modified file 'conf/engines/varchar.zz'
--- conf/engines/varchar.zz	2011-02-28 07:45:36 +0000
+++ conf/engines/varchar.zz	2012-05-16 18:26:06 +0000
@@ -19,7 +19,8 @@ $tables = {
 	rows => [1, 1000, 10000],
 	# 378 is the largest key size possible with --aria-block-size=1K
 	pk => ['VARCHAR(378) NOT NULL' ],
-        partitions => [ undef , 'KEY (pk) PARTITIONS 2' ]
+	# partitions => [ undef , 'KEY (pk) PARTITIONS 2' ],
+	row_formats => [ 'COMPRESSED' ]
 $fields = {
[16 May 2012 18:31] Davi Arnaut

(gdb) bt
#0  0x00007f556ed21d02 in pthread_kill () from /lib64/libpthread.so.0
#1  0x000000000065c4ea in handle_fatal_signal (sig=6) at mysql-trunk/sql/signal_handler.cc:248
#2  <signal handler called>
#3  0x00007f556da18265 in raise () from /lib64/libc.so.6
#4  0x00007f556da19d10 in abort () from /lib64/libc.so.6
#5  0x0000000000a5b5ae in buf_page_get_gen (space=6, zip_size=8192, offset=3026, rw_latch=2, guess=0x0, mode=11, 
    file=0xbffd58 "mysql-trunk/storage/innobase/row/row0row.cc", line=794, mtr=0x41e35b00) at mysql-trunk/storage/innobase/buf/buf0buf.cc:2684
#6  0x0000000000a423eb in btr_cur_search_to_nth_level (index=0x308b638, level=0, tuple=0x3200128, mode=4, latch_mode=2, cursor=0x41e35fa0, has_search_latch=0, 
    file=0xbffd58 "mysql-trunk/storage/innobase/row/row0row.cc", line=794, mtr=0x41e35b00) at mysql-trunk/storage/innobase/btr/btr0cur.cc:627
#7  0x00000000009f082d in btr_pcur_open_low (index=0xf5d5, entry=0x6, mode=4294967295, pcur=0x41e35fa0, mtr=<value optimized out>)
    at mysql-trunk/storage/innobase/include/btr0pcur.ic:440
#8  row_search_index_entry (index=0xf5d5, entry=0x6, mode=4294967295, pcur=0x41e35fa0, mtr=<value optimized out>) at mysql-trunk/storage/innobase/row/row0row.cc:794
#9  0x00000000009ffa47 in row_upd (thr=0x30a3cd8) at mysql-trunk/storage/innobase/row/row0upd.cc:1703
#10 row_upd_step (thr=0x30a3cd8) at mysql-trunk/storage/innobase/row/row0upd.cc:2645
#11 0x00000000009e51eb in row_update_for_mysql (mysql_rec=<value optimized out>, prebuilt=0x7f555c02d7e8) at mysql-trunk/storage/innobase/row/row0mysql.cc:1690
#12 0x000000000096b460 in ha_innobase::delete_row (this=0x7f555c00f190, record=0x7f555c025440 "\373", <incomplete sequence \310>)
    at mysql-trunk/storage/innobase/handler/ha_innodb.cc:6903
#13 0x00000000005822c2 in handler::ha_delete_row (this=0x7f555c00f190, buf=0x7f555c025440 "\373", <incomplete sequence \310>) at mysql-trunk/sql/handler.cc:6927
#14 0x000000000083f1d7 in mysql_delete (thd=0x312df70, table_list=0x3139740, conds=0x3139eb8, order_list=<value optimized out>, limit=1, options=0)
    at mysql-trunk/sql/sql_delete.cc:364
#15 0x00000000006f70b5 in mysql_execute_command (thd=0x312df70) at mysql-trunk/sql/sql_parse.cc:3432
#16 0x00000000006fa915 in mysql_parse (thd=0x312df70, rawbuf=<value optimized out>, length=<value optimized out>, parser_state=0x0) at mysql-trunk/sql/sql_parse.cc:6025
#17 0x00000000006fbc99 in dispatch_command (command=COM_QUERY, thd=0x312df70, 
    packet=0x3131491 "DELETE FROM `table10000_innodb_compressed_varchar_378_not_null` WHERE `col_varchar_1024_utf8` > 'l' LIMIT 1", packet_length=107)
    at mysql-trunk/sql/sql_parse.cc:1275
#18 0x00000000006fc497 in do_command (thd=0x312df70) at mysql-trunk/sql/sql_parse.cc:998
#19 0x00000000006aaef6 in do_handle_one_connection (thd_arg=0x312df70) at mysql-trunk/sql/sql_connect.cc:942
#20 0x00000000006aafd5 in handle_one_connection (arg=0x312df70) at mysql-trunk/sql/sql_connect.cc:858
#21 0x000000000090868b in pfs_spawn_thread (arg=<value optimized out>) at mysql-trunk/storage/perfschema/pfs.cc:1800
#22 0x00007f556ed1c73d in start_thread () from /lib64/libpthread.so.0
#23 0x00007f556dabbf6d in clone () from /lib64/libc.so.6
[16 May 2012 18:32] Davi Arnaut
Haven't been able to reproduce on a debug build yet. Crash usually happens when executing a UPDATE or DELETE statement.
[30 May 2012 17:46] Sveta Smirnova
Thank you for the report.

I can not repeat described behavior with 5.5.23 Linux tar.gz package. Which package do you use? If you build yourself, please, specify compile options you use.
[30 May 2012 19:09] Davi Arnaut
I've built it using the mysql release cmake build configuration. It make take a while to reproduce the issue. Also, this was reproduced on a host with 24 cores.
[1 Jun 2012 11:43] Sveta Smirnova
Thank you for the feedback.

I still can not repeat. Please try with latest version 5.5.25 and if problem still exists provide that real value of duration which I will probably wait to repeat the problem.
[4 Jun 2012 23:16] Davi Arnaut
Can't reproduce using 5.5.25.
[5 Jun 2012 16:19] Sveta Smirnova
Thank you for the update.

Closed as "Can't repeat"