[MDEV-13192] [Draft] InnoDB: Failing assertion: !memcmp(page_zip->data + 38, page + 38, (38 + 36 + 2 * 10) - 38) Created: 2017-06-27  Updated: 2022-09-26  Resolved: 2022-09-26

Status: Closed
Project: MariaDB Server
Component/s: Storage Engine - InnoDB
Affects Version/s: 10.1
Fix Version/s: N/A

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Elena Stepanova
Resolution: Won't Fix Votes: 0
Labels: None
Environment:

3125ba891292ff16186c105b6780fbadc74421e9



 Description   

http://buildbot.askmonty.org/buildbot/builders/qa-kvm-linux/builds/1613/steps/upgr_10.1/logs/stdio

# 2017-06-26T22:53:03 [7688] | 2017-06-26 22:52:58 140232471041920 [Note] InnoDB:  innodb-page-size has been changed from the default value 16384 to 4096 .
# 2017-06-26T22:53:03 [7688] | 2017-06-26 22:52:59 140232471041920 [Note] InnoDB: Using mutexes to ref count buffer pool pages
# 2017-06-26T22:53:03 [7688] | 2017-06-26 22:52:59 140232471041920 [Note] InnoDB:  InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
# 2017-06-26T22:53:03 [7688] | 2017-06-26 22:52:59 140232471041920 [Note] InnoDB:  InnoDB: !!!!!!!! UNIV_SYNC_DEBUG switched on !!!!!!!!!
# 2017-06-26T22:53:03 [7688] | 2017-06-26 22:52:59 140232471041920 [Note] InnoDB: The InnoDB memory heap is disabled
# 2017-06-26T22:53:03 [7688] | 2017-06-26 22:52:59 140232471041920 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
# 2017-06-26T22:53:03 [7688] | 2017-06-26 22:52:59 140232471041920 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
# 2017-06-26T22:53:03 [7688] | 2017-06-26 22:52:59 140232471041920 [Note] InnoDB: Compressed tables use zlib 1.2.8
# 2017-06-26T22:53:03 [7688] | 2017-06-26 22:52:59 140232471041920 [Note] InnoDB: Using Linux native AIO
# 2017-06-26T22:53:03 [7688] | 2017-06-26 22:52:59 140232471041920 [Note] InnoDB: Using generic crc32 instructions
# 2017-06-26T22:53:03 [7688] | 2017-06-26 22:52:59 140232471041920 [Note] InnoDB: Initializing buffer pool, size = 128.0M
# 2017-06-26T22:53:03 [7688] | 2017-06-26 22:52:59 140232471041920 [Note] InnoDB: Completed initialization of buffer pool
# 2017-06-26T22:53:03 [7688] | 2017-06-26 22:52:59 140232471041920 [Note] InnoDB: Highest supported file format is Barracuda.
# 2017-06-26T22:53:03 [7688] | 2017-06-26 22:52:59 140232471041920 [Note] InnoDB: Starting crash recovery from checkpoint LSN=6509822
# 2017-06-26T22:53:03 [7688] | 2017-06-26 22:52:59 140232471041920 [Note] InnoDB: Restoring possible half-written data pages from the doublewrite buffer...
# 2017-06-26T22:53:03 [7688] | 2017-06-26 22:53:01 140232471041920 [Note] InnoDB: Starting final batch to recover 4142 pages from redo log
# 2017-06-26T22:53:03 [7688] | 2017-06-26 22:53:01 7f8a4f3fd700  InnoDB: Assertion failure in thread 140232011798272 in file page0zip.cc line 3479
# 2017-06-26T22:53:03 [7688] | InnoDB: Failing assertion: !memcmp(page_zip->data + 38, page + 38, (38 + 36 + 2 * 10) - 38)
# 2017-06-26T22:53:03 [7688] | InnoDB: We intentionally generate a memory trap.
# 2017-06-26T22:53:03 [7688] | InnoDB: Submit a detailed bug report to http://bugs.mysql.com.
# 2017-06-26T22:53:03 [7688] | InnoDB: If you get repeated assertion failures or crashes, even
# 2017-06-26T22:53:03 [7688] | InnoDB: immediately after the mysqld startup, there may be
# 2017-06-26T22:53:03 [7688] | InnoDB: corruption in the InnoDB tablespace. Please refer to
# 2017-06-26T22:53:03 [7688] | InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
# 2017-06-26T22:53:03 [7688] | InnoDB: about forcing recovery.
# 2017-06-26T22:53:03 [7688] | 170626 22:53:01 [ERROR] mysqld got signal 6 ;
# 2017-06-26T22:53:03 [7688] | This could be because you hit a bug. It is also possible that this binary
# 2017-06-26T22:53:03 [7688] | or one of the libraries it was linked against is corrupt, improperly built,
# 2017-06-26T22:53:03 [7688] | or misconfigured. This error can also be caused by malfunctioning hardware.
# 2017-06-26T22:53:03 [7688] | 
# 2017-06-26T22:53:03 [7688] | To report this bug, see https://mariadb.com/kb/en/reporting-bugs
# 2017-06-26T22:53:03 [7688] | 
# 2017-06-26T22:53:03 [7688] | We will try our best to scrape up some info that will hopefully help
# 2017-06-26T22:53:03 [7688] | diagnose the problem, but since we have already crashed, 
# 2017-06-26T22:53:03 [7688] | something is definitely wrong and this may fail.
# 2017-06-26T22:53:03 [7688] | 
# 2017-06-26T22:53:03 [7688] | Server version: 10.1.25-MariaDB-debug
# 2017-06-26T22:53:03 [7688] | key_buffer_size=134217728
# 2017-06-26T22:53:03 [7688] | read_buffer_size=131072
# 2017-06-26T22:53:03 [7688] | max_used_connections=0
# 2017-06-26T22:53:03 [7688] | max_threads=153
# 2017-06-26T22:53:03 [7688] | thread_count=0
# 2017-06-26T22:53:03 [7688] | It is possible that mysqld could use up to 
# 2017-06-26T22:53:03 [7688] | key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 467211 K  bytes of memory
# 2017-06-26T22:53:03 [7688] | Hope that's ok; if not, decrease some variables in the equation.
# 2017-06-26T22:53:03 [7688] | 
# 2017-06-26T22:53:03 [7688] | Thread pointer: 0x0
# 2017-06-26T22:53:03 [7688] | Attempting backtrace. You can use the following information to find out
# 2017-06-26T22:53:03 [7688] | where mysqld died. If you see no messages after this, something went
# 2017-06-26T22:53:03 [7688] | terribly wrong...
# 2017-06-26T22:53:03 [7688] | stack_bottom = 0x0 thread_stack 0x48400
# 2017-06-26T22:53:03 [7688] | /home/buildbot/build/sql/mysqld(my_print_stacktrace+0x38)[0x7f8a6a2bed28]
# 2017-06-26T22:53:03 [7688] | /home/buildbot/build/sql/mysqld(handle_fatal_signal+0x394)[0x7f8a69c604e3]
# 2017-06-26T22:53:03 [7688] | /lib/x86_64-linux-gnu/libpthread.so.0(+0xf890)[0x7f8a69126890]
# 2017-06-26T22:53:03 [7688] | /lib/x86_64-linux-gnu/libc.so.6(gsignal+0x37)[0x7f8a67224067]
# 2017-06-26T22:53:03 [7688] | /lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7f8a67225448]
# 2017-06-26T22:53:03 [7688] | /home/buildbot/build/sql/mysqld(+0x98cd86)[0x7f8a69ee3d86]
# 2017-06-26T22:53:03 [7688] | mysys/stacktrace.c:267(my_print_stacktrace)[0x7f8a69ee5d96]
# 2017-06-26T22:53:03 [7688] | page/page0zip.cc:3481(page_zip_header_cmp)[0x7f8a69f71b28]
# 2017-06-26T22:53:03 [7688] | btr/btr0cur.cc:3199(btr_cur_parse_del_mark_set_clust_rec(unsigned char*, unsigned char*, unsigned char*, page_zip_des_t*, dict_index_t*))[0x7f8a69ff5da6]
# 2017-06-26T22:53:03 [7688] | log/log0recv.cc:1190(recv_parse_or_apply_log_rec_body)[0x7f8a69ea7dd4]
# 2017-06-26T22:53:03 [7688] | log/log0recv.cc:1749(recv_recover_page_func(unsigned long, buf_block_t*))[0x7f8a69ea926b]
# 2017-06-26T22:53:03 [7688] | buf/buf0buf.cc:4888(buf_page_io_complete(buf_page_t*))[0x7f8a6a021a50]
# 2017-06-26T22:53:03 [7688] | fil/fil0fil.cc:6543(fil_aio_wait(unsigned long))[0x7f8a6a099d56]
# 2017-06-26T22:53:03 [7688] | srv/srv0start.cc:584(io_handler_thread)[0x7f8a69f89d10]
# 2017-06-26T22:53:03 [7688] | /lib/x86_64-linux-gnu/libpthread.so.0(+0x8064)[0x7f8a6911f064]
# 2017-06-26T22:53:03 [7688] | /lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7f8a672d762d]
# 2017-06-26T22:53:03 [7688] | The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
# 2017-06-26T22:53:03 [7688] | information that should help you find out what is causing the crash.
# 2017-06-26T22:53:03 [7688] | Writing a core file
# 2017-06-26T22:53:03 [7688] | Aborted (core dumped)

The test was a crash-upgrade from 10.1.20.

perl /home/buildbot/rqg/runall-new.pl --no-mask --seed=1498531899 --threads=4 --duration=60 --queries=100M --mysqld=--loose-max-statement-time=20 --mysqld=--loose-lock-wait-timeout=20 --mysqld=--innodb-lock-wait-timeout=10 --mysqld=--log-bin --mysqld=--binlog-format=ROW --mysqld=--server-id=111 --grammar=conf/mariadb/oltp.yy --gendata=conf/mariadb/innodb_upgrade.zz --gendata-advanced --upgrade-test=crash --basedir1=/home/buildbot/10.1 --basedir2=/home/buildbot/build --mysqld=--innodb-page-size=4K --mysqld=--innodb-compression-algorithm=zlib --mysqld=--innodb-file-format=Barracuda --mtr-build-thread=300 --vardir1=/home/buildbot/vardir/current1_1

Not reproducible so far.



 Comments   
Comment by Marko Mäkelä [ 2018-02-02 ]

This is using ROW_FORMAT=COMPRESSED. I wonder if this can be explained by the unsafe default value that was introduced by MDEV-6935 in MariaDB 10.1.2 and was in effect until
MDEV-13247 innodb_log_compressed_pages=OFF breaks crash recovery of ROW_FORMAT=COMPRESSED tables
in MariaDB 10.1.26 (and 10.2.7) restored the safe default.

When testing crash-upgrades from MariaDB versions between 10.1.2 and 10.1.26, please remember to set innodb_log_compressed_pages=ON.

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