Apparent corruption of an index page

[luojia]

i backup a database.the backup.log write completed OK,but apply fail，this is the apply log:
InnoDB: End of page dump
InnoDB: Uncompressed page, stored checksum in field1 1270078594, calculated checksums for field1: crc32 875413203/4030998391, innodb 1270078594, none 3735928559, stored checksum in field2 3206620690, c
alculated checksums for field2: crc32 875413203/4030998391, innodb 3206620690, none 3735928559, page LSN 71300 1653834507, low 4 bytes of LSN at page end 1653834507, page number (if stored to page alr
eady) 5216, space id (if created with >= MySQL-4.1.1 and stored already) 0
InnoDB: Page may be a freshly allocated page
[FATAL] InnoDB: Apparent corruption of an index page [page id: space=0, page number=5216] to be written to data file. We intentionally crash the server to prevent corrupt data from ending up in data fi
les.
2017-07-08 15:10:39 0x7f50f04417e0 InnoDB: Assertion failure in thread 139985605105632 in file ut0ut.cc line 916
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.
07:10:39 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
innobackupex(my_print_stacktrace+0x35)[0xd4f415]
innobackupex(handle_fatal_signal+0x273)[0xb5d823]
/lib64/libpthread.so.0(+0xf7e0)[0x7f50f00297e0]
/lib64/libc.so.6(gsignal+0x35)[0x7f50eddea625]
/lib64/libc.so.6(abort+0x175)[0x7f50eddebe05]
innobackupex[0x733a2f]
innobackupex(_ZN2ib5fatalD1Ev+0xb3)[0x8adff3]
innobackupex[0x8e3827]
innobackupex(_Z31buf_dblwr_flush_buffered_writesv+0x35f)[0x8e56cf]
innobackupex(_Z14buf_flush_pageP10buf_pool_tP10buf_page_t11buf_flush_tb+0x49b)[0x977eeb]
innobackupex[0x978c5f]
innobackupex(_Z18buf_flush_do_batchP10buf_pool_t11buf_flush_tmmPm+0x44c)[0x9796ec]
innobackupex(_Z15buf_flush_listsmmPm+0xa6)[0x97a646]
innobackupex[0x869ffb]
innobackupex(_Z17log_check_marginsv+0x411)[0x86fc41]
innobackupex(_Z15que_run_threadsP9que_thr_t+0x3d5)[0x8c5be5]
innobackupex(_Z12que_eval_sqlP11pars_info_tPKcmP5trx_t+0x6e)[0x8c640e]
innobackupex(_Z27row_merge_drop_temp_indexesv+0x6e)[0x7c7aee]
innobackupex(_Z29recv_recovery_rollback_activev+0x25)[0x884075]
innobackupex(_Z34innobase_start_or_create_for_mysqlv+0x2eef)[0x98a7ef]
innobackupex[0x734359]
innobackupex[0x741c7d]
innobackupex(main+0x8ed)[0x74588d]
/lib64/libc.so.6(__libc_start_main+0xfd)[0x7f50eddd6d5d]
innobackupex[0x733a59]

[Jericho Rivera (jericho-rivera)]

which XtraBackup version are you using?
please share the full backup command used and the full prepare command used.
please attach full backup log where backup completed OK.

[luojia (luojia)]

backup log:
170708 04:03:11 innobackupex: Starting the backup operation

IMPORTANT: Please check that the backup run completes successfully.
           At the end of a successful backup run innobackupex
           prints "completed OK!".

170708 04:03:12 version_check Connecting to MySQL server with DSN 'dbi:mysql:;mysql_read_default_group=xtrabackup;port=*;mysql_socket=*/mysql.sock' as 'backup' (using password: YES).
170708 04:03:12 version_check Connected to MySQL server
170708 04:03:12 version_check Executing a version check against the server...
170708 04:03:15 version_check Done.
170708 04:03:15 Connecting to MySQL server host: localhost, user: backup, password: set, port: *, socket: */mysql.sock
Using server version 5.6.28-76.1-log
/usr/bin/innobackupex version 2.4.7 based on MySQL server 5.7.13 Linux (x86_64) (revision id: 05f1fcf)
xtrabackup: uses posix_fadvise().
xtrabackup: cd to *
xtrabackup: open files limit requested 140000, set to 1000000
xtrabackup: using the following InnoDB configuration:
xtrabackup: innodb_data_home_dir = *
xtrabackup: innodb_data_file_path = ibdata1:100M:autoextend
xtrabackup: innodb_log_group_home_dir = *
xtrabackup: innodb_log_files_in_group = 3
xtrabackup: innodb_log_file_size = 1073741824
2017-07-08 04:03:15 0x7fcca26f37e0 InnoDB: Using Linux native AIO
xtrabackup: using O_DIRECT
InnoDB: Number of pools: 1
170708 04:03:15 >> log scanned up to (306228998186115)
xtrabackup: Generating a list of tablespaces
InnoDB: Allocated tablespace ID 7271 for mysql/innodb_table_stats, old maximum was 0
170708 04:03:16 >> log scanned up to (306228998422160)
170708 04:03:17 >> log scanned up to (306228998628892)
170708 04:03:18 >> log scanned up to (306228998827353)
170708 04:03:19 [01] Streaming */var/ibdata1
170708 04:03:19 >> log scanned up to (306228999129667)
170708 04:03:20 >> log scanned up to (306228999553139)
170708 04:03:21 >> log scanned up to (306228999961831)
170708 04:03:22 >> log scanned up to (306229000357828)
170708 04:03:23 >> log scanned up to (306229000611713)
170708 04:03:24 >> log scanned up to (306229000886836)
170708 04:03:25 >> log scanned up to (306229001191660)
170708 04:03:26 >> log scanned up to (306229001437788)
170708 04:03:27 >> log scanned up to (306229001704010)
170708 04:03:28 >> log scanned up to (306229001887089)
170708 04:03:29 >> log scanned up to (306229002103455)
170708 04:03:30 >> log scanned up to (306229002388473)
170708 04:03:31 >> log scanned up to (306229002743365)
170708 04:03:32 >> log scanned up to (306229003033953)
170708 04:03:33 >> log scanned up to (306229003446155)
170708 04:03:34 >> log scanned up to (306229003730886)
170708 04:03:35 >> log scanned up to (306229004043623)
170708 04:03:37 >> log scanned up to (306229004303041)
170708 04:03:38 >> log scanned up to (306229004495058)
170708 04:03:39 >> log scanned up to (306229004684043)
170708 04:03:40 >> log scanned up to (306229004852308)
170708 04:03:41 >> log scanned up to (306229004937549)
170708 04:03:42 >> log scanned up to (306229005283456)
170708 04:03:43 >> log scanned up to (306229005664160)
170708 04:03:44 >> log scanned up to (306229006221751)
170708 04:03:45 >> log scanned up to (306229006...

[Shahriyar Rzayev (rzayev-sehriyar)]

So could you please share the MySQL's my.cnf + exact backup and prepare commands?

[luojia (luojia)]

the commands: innobackupex --apply-log --use-memory=20G ${backup_file_dir} >${backup_file_dir}/apply.log 2>&1
innobackupex version 2.4.7 Linux (x86_64) (revision id: 05f1fcf)
 my.cnf :
[mysql]
port=*
prompt=\\u@\\d\\r:\\m:\\s>
no-auto-rehash

[client]
port=*
socket=*/mysql.sock

[mysqld]
#dir
basedir=/usr
datadir=*
tmpdir=*
log-error=mysql.err
slow_query_log_file=*/mysql.slow
general_log_file=*/mysql.genlog
socket=*/mysql.sock
pid-file=*/mysql.pid

#innodb
innodb_file_format=Barracuda
innodb_data_home_dir=*
innodb_log_group_home_dir=*
innodb_data_file_path=ibdata1:100M:autoextend
innodb_buffer_pool_size=100G
innodb_buffer_pool_instances=4
innodb_log_files_in_group=3
innodb_log_file_size=1G
innodb_log_buffer_size=8M
innodb_flush_log_at_trx_commit=2
innodb_max_dirty_pages_pct=70
innodb_io_capacity=400
innodb_thread_concurrency=0
innodb_read_io_threads=4
innodb_write_io_threads=16
innodb_open_files=60000
innodb_file_per_table=1
innodb_flush_method=O_DIRECT
innodb_change_buffering=all
innodb_adaptive_flushing=1
innodb_old_blocks_time=1000
innodb_use_native_aio=1
innodb_lock_wait_timeout=120
lock_wait_timeout=60
innodb_rollback_on_timeout=0
innodb_buffer_pool_dump_at_shutdown=ON
innodb_buffer_pool_load_at_startup=ON
max_heap_table_size=128M

#myisam
key_buffer_size=32M
myisam_sort_buffer_size=128M
concurrent_insert=ALWAYS
delayed_insert_timeout=300
read_rnd_buffer_size=128K
myisam-recover-options=default

#replication
skip-slave-start
relay-log=relay
slave_load_tmpdir=*

#binlog
log-bin=mysql-bin
server_id=32120007
report_host=10.32.120.7
report_port=5002
binlog_cache_size=1M
max_binlog_cache_size=2G
max_binlog_size=1024M
binlog-format=row
#sync_binlog=1
log-slave-updates
read_only=ON
expire_logs_days=7
max_binlog_files=0
binlog_rows_query_log_events=ON

#server
default-storage-engine=INNODB
character-set-server=utf8mb4
collation_server=utf8mb4_unicode_ci
character_set_client=utf8mb4
open_files_limit=140000
log_slow_admin_statements=1
log_slow_verbosity=microtime,query_plan,innodb
log_warnings=2
#log_queries_not_using_indexes=1
long_query_time=0.100000
slow_query_log=1
log_slow_slave_statements=1
query_cache_type=0
query_cache_size=256M
query_cache_limit=1M
query_cache_min_res_unit=1K
table_definition_cache=65536
table_open_cache=65536
thread_stack=512K
thread_cache_size=256
sort_buffer_size=8M
join_buffer_size=8M
read_buffer_size=128K
port=5002
skip-name-resolve
skip-ssl
max_connections=2000
max_connect_errors=65536
max_allowed_packet=16M
connect_timeout=8
net_read_timeout=30
net_write_timeout=60
slave_net_timeout=90
back_log=1024

#When this variable is enabled, InnoDB updates statistics during metadata statements such as SHOW TABLE STATUS or SHOW INDEX, or when accessing the INFORMATION_SCHEMA tables TABLES or STATISTICS. (These updates are similar to what happens for ANALYZE TABLE.) When disabled, InnoDB does not update statistics during these operations. Leaving this setting disabled can improve access speed for schemas that have a large number of tables or indexes. It can also improve the stability of execution plans for queries that involve InnoDB tables.
innodb_stats_on_metadata=OFF

#because bug https://bugs.launchpad.net/percona-server/...

[Shahriyar Rzayev (rzayev-sehriyar)]

Thanks,
So this is your prepare command:

innobackupex --apply-log --use-memory=20G ${backup_file_dir} >${backup_file_dir}/apply.log 2>&1

And what is your backup command?

[luojia (luojia)]

sudo ${innodbackup} --defaults-file=${mycnf} --user=${user} --password=${password} \
       --slave-info --lock-wait-threshold=5 --lock-wait-query-type=all --lock-wait-timeout=60 \
       --stream=tar /*/tmp --no-timestamp --socket=${socket} \
       | lz4 -B4 | pv -q -L${netlimit} | nc $localhost 9988

[Shahriyar Rzayev (rzayev-sehriyar)]

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