Failing assertion: dblwr_recover || memcmp(src + 16 + 4, src + (header.m_original_size + 38U) - 8 + 4, 4) == 0

[Shahriyar Rzayev]

The result of PTB run:

with PXB optimized build:

161114 21:16:21 version_check Connecting to MySQL server with DSN 'dbi:mysql:;mysql_read_default_group=xtrabackup;port=10000;mysql_socket=/tmp/mysql.sock' as 'jenkins' (using password: NO).
161114 21:16:21 version_check Connected to MySQL server
161114 21:16:21 version_check Executing a version check against the server...
161114 21:16:21 version_check Done.
161114 21:16:21 Connecting to MySQL server host: localhost, user: jenkins, password: not set, port: 10000, socket: /tmp/mysql.sock
Using server version 5.7.15-9-log
xtrabackup version 2.4.4 based on MySQL server 5.7.13 Linux (x86_64) (revision id: )
xtrabackup: uses posix_fadvise().
xtrabackup: cd to /mnt/workspace/PTB-run-percona-server-5.7-pxb-2.4.4/BTYPE/release/Host/centos7-64/mnt/var/ps_5.7.15_sysbench/test-0/mysql.1/data
xtrabackup: open files limit requested 0, set to 1048576
xtrabackup: using the following InnoDB configuration:
xtrabackup: innodb_data_home_dir = .
xtrabackup: innodb_data_file_path = ibdata1:12M:autoextend
xtrabackup: innodb_log_group_home_dir = ./
xtrabackup: innodb_log_files_in_group = 2
xtrabackup: innodb_log_file_size = 1073741824
xtrabackup: using O_DIRECT
InnoDB: Number of pools: 1
161114 21:16:23 >> log scanned up to (595839183)
xtrabackup: Generating a list of tablespaces
InnoDB: Allocated tablespace ID 47 for sbtest/sbtest3, old maximum was 0
161114 21:16:24 [01] Copying ./ibdata1 to /mnt/workspace/PTB-run-percona-server-5.7-pxb-2.4.4/BTYPE/release/Host/centos7-64/mnt/var/ps_5.7.15_sysbench/test-0/backup-0.0/ibdata1
161114 21:16:24 [01] ...done
161114 21:16:24 [01] Copying ./sbtest/sbtest3.ibd to /mnt/workspace/PTB-run-percona-server-5.7-pxb-2.4.4/BTYPE/release/Host/centos7-64/mnt/var/ps_5.7.15_sysbench/test-0/backup-0.0/sbtest/sbtest3.ibd
[01] xtrabackup: Database page corruption detected at page 35, retrying...
[01] xtrabackup: Database page corruption detected at page 35, retrying...
[01] xtrabackup: Database page corruption detected at page 35, retrying...
[01] xtrabackup: Database page corruption detected at page 35, retrying...
161114 21:16:24 >> log scanned up to (596098807)
[01] xtrabackup: Database page corruption detected at page 35, retrying...
[01] xtrabackup: Database page corruption detected at page 35, retrying...
[01] xtrabackup: Database page corruption detected at page 35, retrying...
[01] xtrabackup: Database page corruption detected at page 35, retrying...
[01] xtrabackup: Database page corruption detected at page 35, retrying...
[01] xtrabackup: Error: failed to read page after 10 retries. File ./sbtest/sbtest3.ibd seems to be corrupted.
[01] xtrabackup: Error: xtrabackup_copy_datafile() failed.
[01] xtrabackup: Error: failed to copy datafile.

With PXB debug build:

161114 21:15:32 [01] Copying ./sbtest/sbtest5.ibd to /mnt/workspace/PTB-run-percona-server-5.7-pxb-2.4.4/BTYPE/debug/Host/centos7-64/mnt/var/ps_5.7.15_sysbench/test-0/backup-0.0/sbtest/sbtest5.ibd
2016-11-14 21:15:32 0x7f38adc7b700 InnoDB: Assertion failure in thread 139881410443008 in file os0file.cc line 8594
InnoDB: Failing assertion: dblwr_recover || memcmp(src + 16 + 4, src + (header.m_original_size + 38U) - 8 + 4, 4) == 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.
21:15:32 UTC - xtrabackup got signal 6 ;
This could be because you hit a bug or data is corrupted.
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.

Thread pointer: 0x0
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 = 0 thread_stack 0x10000
xtrabackup(my_print_stacktrace+0x35)[0x16857d5]
xtrabackup(handle_fatal_signal+0x2ab)[0x1575521]
/lib64/libpthread.so.0(+0xf100)[0x7f38b7233100]
/lib64/libc.so.6(gsignal+0x37)[0x7f38b558a5f7]
/lib64/libc.so.6(abort+0x148)[0x7f38b558bce8]
xtrabackup[0x10e7d7f]
xtrabackup(_ZN11Compression11deserializeEbPhS0_m+0x381)[0x10cb8bd]
xtrabackup(_Z23os_file_decompress_pagebPhS_m+0x30)[0x10cb92e]
xtrabackup(_Z15xb_fil_cur_readP12xb_fil_cur_t+0x4a7)[0xe00548]
xtrabackup[0xde2b1e]
xtrabackup[0xde3a35]
/lib64/libpthread.so.0(+0x7dc5)[0x7f38b722bdc5]
/lib64/libc.so.6(clone+0x6d)[0x7f38b564bced]

Please report a bug at https://bugs.launchpad.net/percona-xtrabackup

[Shahriyar Rzayev (rzayev-sehriyar)]

my.cnf:

[client]
port=10000
socket=/tmp/mysql.sock
user=root
[mysqld]
basedir=/mnt/workspace/PTB-run-percona-server-5.7-pxb-2.4.4/BTYPE/release/Host/centos7-64/Percona-Server-5.7.15-9-Linux.x86_64.ssl101
datadir=/mnt/workspace/PTB-run-percona-server-5.7-pxb-2.4.4/BTYPE/release/Host/centos7-64/mnt/var/ps_5.7.15_sysbench/test-0/mysql.1/data
tmpdir=/mnt/workspace/PTB-run-percona-server-5.7-pxb-2.4.4/BTYPE/release/Host/centos7-64/mnt/var/ps_5.7.15_sysbench/test-0/mysql.1/tmp
port=10000
socket=/tmp/mysql.sock
pid-file=/mnt/workspace/PTB-run-percona-server-5.7-pxb-2.4.4/BTYPE/release/Host/centos7-64/mnt/var/ps_5.7.15_sysbench/test-0/mysql.1/mysql.pid
innodb_page_size=64k
early_plugin_load=keyring_file.so
keyring_file_data=/mnt/workspace/PTB-run-percona-server-5.7-pxb-2.4.4/BTYPE/release/Host/centos7-64/mnt/var/ps_5.7.15_sysbench/test-0/mysql.1/data/keyring
console
user=jenkins
server-id=1
general-log-file=/mnt/workspace/PTB-run-percona-server-5.7-pxb-2.4.4/BTYPE/release/Host/centos7-64/mnt/var/ps_5.7.15_sysbench/test-0/mysql.1/query.log

binlog-format=row
innodb_buffer_pool_size=1G
innodb_checksums=ON
innodb_file_format=antelope
innodb_file_per_table=1
innodb_flush_log_at_trx_commit=1
innodb_flush_method=O_DIRECT
innodb_log_file_size=1G
log-bin=
log-bin-index=

[Shahriyar Rzayev (rzayev-sehriyar)]

General reproduce path:

1. Initialize/start PS 5.7.15 with innodb_page_size=64k + keyring plugin
2. Create tables using sysbench:
sysbench --test=/usr/share/doc/sysbench//tests/db/parallel_prepare.lua --mysql-socket=/tmp/mysql.sock --mysql-user=root --oltp-tables-count=16 --oltp-table-size=100000 --num-threads=8 --mysql-table-engine=innodb run
3.
alter table sbtest.sbtest1 compression='lz4';
alter table sbtest.sbtest2 compression='lz4';
alter table sbtest.sbtest3 compression='lz4';
alter table sbtest.sbtest4 compression='lz4';
alter table sbtest.sbtest5 compression='lz4';

optimize table sbtest.sbtest1;
optimize table sbtest.sbtest2;
optimize table sbtest.sbtest3;
optimize table sbtest.sbtest4;
optimize table sbtest.sbtest5;

alter table sbtest.sbtest1 encryption='Y';
alter table sbtest.sbtest2 encryption='Y';
alter table sbtest.sbtest3 encryption='Y';
alter table sbtest.sbtest4 encryption='Y';
alter table sbtest.sbtest5 encryption='Y';

4.
Running sysbench:
sysbench --test=/usr/share/doc/sysbench/tests/db/oltp.lua --mysql-socket=/tmp/mysql.sock --mysql-user=root --oltp-tables-count=16 --oltp-table-size=100000 --num-threads=2 --mysql-table-engine=innodb --max-time=0 --max-requests=0 --percentile=99 --report-interval=30 run

5. Try to backup:
xtrabackup --defaults-file=/mnt/workspace/PTB-run-percona-server-5.7-pxb-2.4.4/BTYPE/release/Host/centos7-64/mnt/var/ps_5.7.15_sysbench/test-0/mysql.1/my.cnf --no-timestamp --tmpdir=/mnt/workspace/PTB-run-percona-server-5.7-pxb-2.4.4/BTYPE/release/Host/centos7-64/mnt/var/ps_5.7.15_sysbench/test-0 --parallel=1 --target-dir=/mnt/workspace/PTB-run-percona-server-5.7-pxb-2.4.4/BTYPE/release/Host/centos7-64/mnt/var/ps_5.7.15_sysbench/test-0/backup-0.0 --keyring-file-data=/mnt/workspace/PTB-run-percona-server-5.7-pxb-2.4.4/BTYPE/release/Host/centos7-64/mnt/var/ps_5.7.15_sysbench/test-0/mysql.1/data/keyring --backup

[Shahriyar Rzayev (rzayev-sehriyar)]

Interesting thing here is that, if you specify 'zlib' instead of 'lz4' it will fail on page 5:

[01] xtrabackup: Database page corruption detected at page 5, retrying...
[01] xtrabackup: Database page corruption detected at page 5, retrying...
[01] xtrabackup: Database page corruption detected at page 5, retrying...
[01] xtrabackup: Database page corruption detected at page 5, retrying...

[Shahriyar Rzayev (rzayev-sehriyar)]

Same thing is happening is you start MySQL with innodb_page_size=16K(default) as well.

2017-11-22 22:45:24 DEBUG Will start MySQL with --innodb_buffer_pool_size=1G --innodb_log_file_size=1G --innodb_page_size=16K --early-plugin-load=keyring_file.so --keyring_file_data=/home/shahriyar.rzaev/XB_TEST/server_dir/PS211117-percona-server-5.7.19-17-linux-x86_64-debug/mysql-keyring/keyring --log-bin=mysql-bin --log-slave-updates --server-id=3 --gtid-mode=ON --enforce-gtid-consistency --binlog-format=row

2017-11-22 22:48:14 DEBUG The following backup command will be executed /home/shahriyar.rzaev/XB_TEST/server_dir/target/percona-xtrabackup-2.4.x-debug/bin/xtrabackup --defaults-file= --user=root --password='' --target-dir=/home/shahriyar.rzaev/XB_TEST/backup_dir/ps_5_7_x_2_4/cycle3/full/2017-11-22_22-48-14 --backup --socket=/home/shahriyar.rzaev/XB_TEST/server_dir/PS211117-percona-server-5.7.19-17-linux-x86_64-debug/socket.sock --compress=quicklz --compress-chunk-size=65536 --compress-threads=4 --encrypt=AES256 --encrypt-key=VVTBwgM4UhwkTTV98fhuj+D1zyWoA89K --encrypt-threads=4 --encrypt-chunk-size=65536 --slave-info --no-version-check --core-file --parallel=10 --throttle=40 --keyring-file-data=/home/shahriyar.rzaev/XB_TEST/server_dir/PS211117-percona-server-5.7.19-17-linux-x86_64-debug/mysql-keyring/keyring --stream="xbstream" > /home/shahriyar.rzaev/XB_TEST/backup_dir/ps_5_7_x_2_4/cycle3/full/2017-11-22_22-48-14/full_backup.stream

171122 22:48:17 [05] Compressing, encrypting and streaming ./sysbench_test_db/sbtest3.ibd
2017-11-22 22:48:17 0x7f285ebfe700 InnoDB: Assertion failure in thread 139811365054208 in file os0file.cc line 8594
InnoDB: Failing assertion: dblwr_recover || memcmp(src + 16 + 4, src + (header.m_original_size + 38U) - 8 + 4, 4) == 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:48:17 UTC - xtrabackup got signal 6 ;
This could be because you hit a bug or data is corrupted.
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.

Thread pointer: 0x0
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 = 0 thread_stack 0x10000
/home/shahriyar.rzaev/XB_TEST/server_dir/target/percona-xtrabackup-2.4.x-debug/bin/xtrabackup(my_print_stacktrace+0x35)[0x17f6fce]
/home/shahriyar.rzaev/XB_TEST/server_dir/target/percona-xtrabackup-2.4.x-debug/bin/xtrabackup(handle_fatal_signal+0x2ab)[0x1165f8f]
/usr/lib64/libpthread.so.0(+0xf130)[0x7f28add1a130]
/usr/lib64/libc.so.6(gsignal+0x37)[0x7f28aba195d7]
/usr/lib64/libc.so.6(abort+0x148)[0x7f28aba1acc8]
/home/shahriyar.rzaev/XB_TEST/server_dir/ta...

[Shahriyar Rzayev (rzayev-sehriyar)]

Percona now uses JIRA for bug reports so this bug report is migrated to: https://jira.percona.com/browse/PXB-488