innobackupex apply-log error on percona-xtrabackup-24-2.4.12-1.el6.x86_64 is a bug?

InnoDB: Log record type 47, page 1889675:1. Log parsing proceeded successfully up to 15970656365006. Previous log record type 4, is multi 0 Recv offset 47063, prev 47055
InnoDB: Hex dump starting 100 bytes before and ending 100 bytes after the corrupted record:
len 208; hex 81b8003c780400c7c00d0078f0ffffffff0200c7c00d007c000400c7c00d007ef0ffffffff0200c7c00d008200040081b8002e010800c7c00d005e0af0eb2ff80200c7c00d0066001faa8762961e000300038004800880080c67880007002e00001cd59a840007003edcd58bafdcd58b01000001000017746d702f2373716c323030395f313937353062635f30001ddcd58b011bdcd58b011f1ddcd58b0002dcd58b0000180804dcd58b000026dcd58b04dcd58b00002a0004dcd58b00002e0404dcd58b0000320004dcd58b00003681; asc <x x | ~ . ^ / f b g . > tmp/#sql2009_19750bc_0 & * . 2 6 ;
InnoDB: Set innodb_force_recovery to ignore this error.
InnoDB: Plugin initialization aborted with error Generic error
xtrabackup: innodb_init(): Error occured.

my mysql slave has some sql like this: CREATE temporary TABLE if not exists xx.temp_user_adjust_data …; insert ignore into xx.temp_user_adjust_data (dev …; when i backup mysql database;

my mysql version is 5.6.34

innobackupex version 2.4.12 based on MySQL server 5.7.19 Linux (x86_64) (revision id: 170eb8c)
xtrabackup: cd to /data/bak/evonymob/
xtrabackup: This target seems to be not prepared yet.
InnoDB: Number of pools: 1
xtrabackup: xtrabackup_logfile detected: size=150732800, start_lsn=(15970656316439)
xtrabackup: using the following InnoDB configuration for recovery:
xtrabackup: innodb_data_home_dir = .
xtrabackup: innodb_data_file_path = ibdata1:1G:autoextend
xtrabackup: innodb_log_group_home_dir = .
xtrabackup: innodb_log_files_in_group = 1
xtrabackup: innodb_log_file_size = 150732800
xtrabackup: using the following InnoDB configuration for recovery:
xtrabackup: innodb_data_home_dir = .
xtrabackup: innodb_data_file_path = ibdata1:1G:autoextend
xtrabackup: innodb_log_group_home_dir = .
xtrabackup: innodb_log_files_in_group = 1
xtrabackup: innodb_log_file_size = 150732800
xtrabackup: Starting InnoDB instance for recovery.
xtrabackup: Using 17179869184 bytes for buffer pool (set by --use-memory parameter)
InnoDB: PUNCH HOLE support available
InnoDB: Mutexes and rw_locks use GCC atomic builtins
InnoDB: Uses event mutexes
InnoDB: GCC builtin __sync_synchronize() is used for memory barrier
InnoDB: Compressed tables use zlib 1.2.3
InnoDB: Number of pools: 1
InnoDB: Using CPU crc32 instructions
InnoDB: Initializing buffer pool, total size = 16G, instances = 1, chunk size = 128M
InnoDB: Completed initialization of buffer pool
InnoDB: page_cleaner coordinator priority: -20
InnoDB: Highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 15970656316439
InnoDB: ############### CORRUPT LOG RECORD FOUND ##################
InnoDB: Log record type 47, page 1889675:1. Log parsing proceeded successfully up to 15970656365006. Previous log record type 4, is multi 0 Recv offset 47063, prev 47055
InnoDB: Hex dump starting 100 bytes before and ending 100 bytes after the corrupted record:
len 208; hex 81b8003c780400c7c00d0078f0ffffffff0200c7c00d007c000400c7c00d007ef0ffffffff0200c7c00d008200040081b8002e010800c7c00d005e0af0eb2ff80200c7c00d0066001faa8762961e000300038004800880080c67880007002e00001cd59a840007003edcd58bafdcd58b01000001000017746d702f2373716c323030395f313937353062635f30001ddcd58b011bdcd58b011f1ddcd58b0002dcd58b0000180804dcd58b000026dcd58b04dcd58b00002a0004dcd58b00002e0404dcd58b0000320004dcd58b00003681; asc <x x | ~ . ^ / f b g . > tmp/#sql2009_19750bc_0 & * . 2 6 ;
InnoDB: Set innodb_force_recovery to ignore this error.
InnoDB: Plugin initialization aborted with error Generic error
xtrabackup: innodb_init(): Error occured.

Can you confirm that this only happens during prepare phase (apply-log)? Please send us full innobackupex command used and directory listing of your backup you are preparing.

innobackupex --defaults-file=/etc/my-myservice.cnf --socket=/data1/mysql/myservice/tmp/mysql.sock --tmpdir=/data1/mysqlbak/myservice --user=backupuser --password=xxxxx --encrypt=AES256 --encrypt-key-file=/home/mysql/crontab/xtrabackup/keyfile --encrypt-threads=4 --compress --compress-threads=4 --parallel=4 --lock-wait-threshold=40 --lock-wait-query-type=update --lock-wait-timeout=180 --kill-long-queries-timeout=20 --kill-long-query-type=select --stream=xbstream --no-timestamp --slave-info /data1/mysqlbak/myservice/full 2>/data1/mysqlbak/myservice/mysqlbackup_20190602-200100.log > /data1/mysqlbak/myservice/myservice_full_20190602-200100.xbstream
the myservice/mysqlbackup_20190602-200100.log has
like this :

190602 20:11:45 [00] Compressing, encrypting and streaming
190602 20:11:45 [00] …done
190602 20:11:45 [00] Compressing, encrypting and streaming
190602 20:11:45 [00] …done
xtrabackup: Transaction log of lsn (15970656316439) to (15970775448294) was copied.
190602 20:11:45 completed OK!

so i use this file myservice/myservice_full_20190602-200100.xbstream to recovery, this is my commands:
xbstream --parallel=8 --encrypt-threads=8 --decrypt=AES256 --encrypt-key-file=/home/mysql/crontab/xtrabackup/keyfile -C /data/bak/myservice -x < myservice_full_20190602-200100.xbstream

innobackupex --parallel=24 --decompress /data/bak/myservice 2>/data/bak/myservice-decompress.log

the myservice-decompress.log has:
190605 02:24:27 [13] decompressing ./xtrabackup_slave_info.qp
190605 02:24:27 [11] decompressing ./xtrabackup_binlog_info.qp
190605 02:24:27 [03] decompressing ./backup-my.cnf.qp
190605 02:24:27 [07] decompressing ./xtrabackup_info.qp
190605 02:27:21 completed OK!

innobackupex --defaults-file=/etc/my-myservice.cnf --use-memory=16G --apply-log /data/bak/myservice 2>/data/bak/myservice-apply-log.log

cat myservice-apply-log.log
xtrabackup: recognized server arguments: --innodb_checksum_algorithm=crc32 --innodb_log_checksum_algorithm=innodb --innodb_data_file_path=ibdata1:1G:autoextend --innodb_log_files_in_group=2 --innodb_log_file_size=4294967296 --innodb_fast_checksum=0 --innodb_page_size=8192 --innodb_log_block_size=512 --innodb_undo_directory=. --innodb_undo_tablespaces=0 --server-id=168887312 --redo-log-version=0
xtrabackup: recognized client arguments: --innodb_checksum_algorithm=crc32 --innodb_log_checksum_algorithm=innodb --innodb_data_file_path=ibdata1:1G:autoextend --innodb_log_files_in_group=2 --innodb_log_file_size=4294967296 --innodb_fast_checksum=0 --innodb_page_size=8192 --innodb_log_block_size=512 --innodb_undo_directory=. --innodb_undo_tablespaces=0 --server-id=168887312 --redo-log-version=0
190605 02:27:21 innobackupex: Starting the apply-log operation

IMPORTANT: Please check that the apply-log run completes successfully.
At the end of a successful apply-log run innobackupex
prints “completed OK!”.

innobackupex version 2.4.14 based on MySQL server 5.7.19 Linux (x86_64) (revision id: ef675d4)
xtrabackup: cd to /data/bak/myservice/
xtrabackup: This target seems to be not prepared yet.
InnoDB: Number of pools: 1
xtrabackup: xtrabackup_logfile detected: size=134021120, start_lsn=(15970656316439)
xtrabackup: using the following InnoDB configuration for recovery:
xtrabackup: innodb_data_home_dir = .
xtrabackup: innodb_data_file_path = ibdata1:1G:autoextend
xtrabackup: innodb_log_group_home_dir = .
xtrabackup: innodb_log_files_in_group = 1
xtrabackup: innodb_log_file_size = 134021120
xtrabackup: using the following InnoDB configuration for recovery:
xtrabackup: innodb_data_home_dir = .
xtrabackup: innodb_data_file_path = ibdata1:1G:autoextend
xtrabackup: innodb_log_group_home_dir = .
xtrabackup: innodb_log_files_in_group = 1
xtrabackup: innodb_log_file_size = 134021120
xtrabackup: Starting InnoDB instance for recovery.
xtrabackup: Using 25769803776 bytes for buffer pool (set by --use-memory parameter)
InnoDB: PUNCH HOLE support available
InnoDB: Mutexes and rw_locks use GCC atomic builtins
InnoDB: Uses event mutexes
InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
InnoDB: Compressed tables use zlib 1.2.3
InnoDB: Number of pools: 1
InnoDB: Using CPU crc32 instructions
InnoDB: Initializing buffer pool, total size = 24G, instances = 1, chunk size = 128M
InnoDB: Completed initialization of buffer pool
InnoDB: page_cleaner coordinator priority: -20
InnoDB: Highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 15970656316439
InnoDB: ############### CORRUPT LOG RECORD FOUND ##################
InnoDB: Log record type 47, page 1889675:1. Log parsing proceeded successfully up to 15970656365006. Previous log record type 4, is multi 0 Recv offset 47063, prev 47055
InnoDB: Hex dump starting 100 bytes before and ending 100 bytes after the corrupted record:
len 208; hex 81b8003c780400c7c00d0078f0ffffffff0200c7c00d007c000400c7c00d007ef0ffffffff0200c7c00d008200040081b8002e010800c7c00d005e0af0eb2ff80200c7c00d0066001faa8762961e000300038004800880080c67880007002e00001cd59a840007003edcd58bafdcd58b01000001000017746d702f2373716c323030395f313937353062635f30001ddcd58b011bdcd58b011f1ddcd58b0002dcd58b0000180804dcd58b000026dcd58b04dcd58b00002a0004dcd58b00002e0404dcd58b0000320004dcd58b00003681; asc <x x | ~ . ^ / f b g . > tmp/#sql2009_19750bc_0 & * . 2 6 ;
InnoDB: Set innodb_force_recovery to ignore this error.
InnoDB: Plugin initialization aborted with error Generic error
xtrabackup: innodb_init(): Error occured.

this is all the log;
When i use percona-xtrabackup-2.3.10-1.el6.x86_64.rpm or percona-xtrabackup-22-2.2.13-1.el6.x86_64.rpm to backup dababase and recovery database,it is successful.
When i use percona-xtrabackup-24-2.4.12-1.el6.x86_64.rpm or percona-xtrabackup-24-2.4.14-1.el6.x86_64.rpm to backup database is successful,but recovery is fail;

this temporary sql Execute once every two minutes:

CREATE temporary TABLE if not exists xxxx.temp_user_adjust_data (
device_id varchar(64) NOT NULL DEFAULT ‘’,
gps_adid varchar(100) NOT NULL DEFAULT ‘’,
adid varchar(100) NOT NULL DEFAULT ‘’,
country varchar(10) NOT NULL DEFAULT ‘’,
tracker_id int(10) NOT NULL DEFAULT 0,
click_time int(10) NOT NULL DEFAULT 0,
installed_at int(10) NOT NULL DEFAULT 0,
label_user_id bigint(20) NOT NULL DEFAULT 0,
label_sns int(5) NOT NULL DEFAULT 0,
label_step int(5) NOT NULL DEFAULT 0,
KEY device_id (device_id),
KEY gps_adid (gps_adid),
KEY adid (adid)
)
1393 Query select count() as nums from xxxx.temp_user_adjust_data
1393 Query drop table xxxx.temp_user_adjust_data
1393 Query CREATE temporary TABLE if not exists xxxx.temp_user_adjust_data (
device_id varchar(64) NOT NULL DEFAULT ‘’,
gps_adid varchar(100) NOT NULL DEFAULT ‘’,
adid varchar(100) NOT NULL DEFAULT ‘’,
country varchar(10) NOT NULL DEFAULT ‘’,
tracker_id int(10) NOT NULL DEFAULT 0,
click_time int(10) NOT NULL DEFAULT 0,
installed_at int(10) NOT NULL DEFAULT 0,
label_user_id bigint(20) NOT NULL DEFAULT 0,
label_sns int(5) NOT NULL DEFAULT 0,
label_step int(5) NOT NULL DEFAULT 0,
KEY device_id (device_id),
KEY gps_adid (gps_adid),
KEY adid (adid)
)
1393 Query insert ignore into xxxx.temp_user_adjust_data (device_id, gps_adid, adid, country, tracker_id,click_time,installed_at,label_user_id, label_sns, label_step) values (‘’,‘fb5e1658-673e-4251-bde9-c88b110ba06a’,‘50d1618a0e3b53e01785d5c1f45ba8cc’,‘jo’,‘331296’,‘1559566755’,‘1559566854’,‘0’,‘0’,‘0’),(‘’,‘c65dff11-db74-4b26-aa61-1363ae65dc20’,‘9bfa88f5b259ccbf8cd6236b6b7bd4a5’,‘th’,‘330427’,‘1559564877’,‘1559566907’,‘0’,‘0’,‘0’),(‘’,‘e00a9dc4-1c7e-44db-b7c2-5005f39f023b’,‘e90d8b1ed7770fc273c97c2681696394’,‘eg’,‘660’,‘0’,‘1559566950’,‘0’,‘0’,‘0’),(‘’,‘15a5dd7b-ca9e-49be-aa6a-b9dee0335931’,‘bf621dab6bbf88a002d49ebaceebcf4b’,‘vn’,‘331295’,‘1559566803’,‘1559566964’,‘0’,‘0’,‘0’)
1393 Query select count(
) as nums from xxxx.temp_user_adjust_data
select a.user_id, u.uin, tracker_id,label_user_id, label_sns,label_step,installed_at from yyy.ad_track as a, yyy.user_server as u, xxxx.temp_user_adjust_data as b
where a.user_id = u.user_id and u.ticket is null and a.ad_id = b.adid and a.ad_id != ‘’ and b.adid != ‘’ limit 0, 5000

1656 Query SELECT SUM(compress_time) AS compress_time, SUM(uncompress_time) AS uncompress_time FROM information_schema.INNODB_CMP

1657 Query SET NAMES utf8
1657 Query set autocommit=0
1657 Query SELECT SUM(trx_rows_locked) AS rows_locked, SUM(trx_rows_modified) AS rows_modified, SUM(trx_lock_memory_bytes) AS lock_memory FROM information_schema.INNODB_TRX
1657 Quit
1658 Query SET NAMES utf8
1658 Query set autocommit=0
1658 Query SELECT LOWER(REPLACE(trx_state, " ", “_”)) AS state, count(*) AS cnt from information_schema.INNODB_TRX GROUP BY state ORDER BY state

some big select sql like this:
select a.user_id, u.uin, tracker_id,label_user_id, label_sns,label_step,installed_at from yyy.ad_track as a, yyy.user_server as u, xxxx.temp_use r_adjust_data as b
where a.user_id = u.user_id and u.ticket is null and a.gps_adid = b.gps_adid and a.gps_adid != ‘’ and b.gps_adid != ‘’ limit 0, 5000

this is something get form general.log

I may have missed the info about the mysql version used here. Since it is MySQL 5.6.34 then it is still advisable to use percona-xtrabackup 2.3 instead of PXB 2.4.

ok.Thank you. Can this problem be solved in PXB 2.4 ? there is possible something changes for temporary table in redo log in mysql 5.6 and 5.7.