Restore fail

[mejsin]

[03] Checking if there are indexes to rebuild in table uniwiserest/RefSubmission
FailedDocuments (space id: 126)
[03] Found index FK_RefSubmissionFailedDocuments_SubmissionFailed
[03] Found index FK_RefSubmissionFailedDocuments_SubmissionDocuments
2017-03-27 18:26:06 0x7fe867ff7700 InnoDB: Assertion failure in thread 14063615
3935616 in file compact.cc line 821
InnoDB: Failing assertion: dict_foreign_replace_index(table, NULL, index)
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.
18:26:06 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+0x2c)[0xc1f7ec]
xtrabackup(handle_fatal_signal+0x262)[0xa29392]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x10340)[0x7fe8abb72340]
/lib/x86_64-linux-gnu/libc.so.6(gsignal+0x39)[0x7fe8a9a95cc9]
/lib/x86_64-linux-gnu/libc.so.6(abort+0x148)[0x7fe8a9a990d8]
xtrabackup[0x6f7c37]
xtrabackup[0x72d10c]
/lib/x86_64-linux-gnu/libpthread.so.0(+0x8182)[0x7fe8abb6a182]
/lib/x86_64-linux-gnu/libc.so.6(clone+0x6d)[0x7fe8a9b5947d]

Please report a bug at https://bugs.launchpad.net/percona-xtrabackup
2017-03-27T18:26:06UTC - Removing encrypted files

[mejsin (mejsin)]

This command is run:
xtrabackup --defaults-file=/tmp/restore/backup-my.cnf -
-prepare --target-dir=/tmp/restore/ --rebuild-indexes --rebuild-threads=8

[Sergei Glushchenko (sergei.glushchenko)]

Looks like duplicate of bug 1192834

[mejsin (mejsin)]

We don't use compact, so must be a different issue ....

[mejsin (mejsin)]

But we use a setting for innodb_log_file_size:
innodb_log_file_size = 1G

and seems this gives some issue when restoring with xtrabackup ?
I tried xtrabackup --defaults-file=/.../<ourfolder>/my.cnf but still I see a ib_logfile0 on 8M is created and not 1GB ? can you pleasy guide in the correct way to restore

[mejsin (mejsin)]

I see a backup-my.cnf created i restore-folder as:
[mysqld]
innodb_checksum_algorithm=innodb
innodb_log_checksum_algorithm=innodb
innodb_data_file_path=ibdata1:12M:autoextend
innodb_log_files_in_group=2
innodb_log_file_size=1073741824
innodb_fast_checksum=false
innodb_page_size=16384
innodb_log_block_size=512
innodb_undo_directory=.
innodb_undo_tablespaces=0
server_id=0

redo_log_version=0

[mejsin (mejsin)]

but ib_logfile0 is 8M

[mejsin (mejsin)]

xtrabackup version 2.4.6 based on MySQL server 5.7.13 Linux (x86_64) (revision id: 8ec05b7)

[mejsin (mejsin)]

could it be related to bug 1528271 ??

[mejsin (mejsin)]

On starting the galera server I see this in log:
2017-03-27 20:19:15 140002001598400 [Note] InnoDB: Using mutexes to ref count buffer pool pages
2017-03-27 20:19:15 140002001598400 [Note] InnoDB: The InnoDB memory heap is disabled
2017-03-27 20:19:15 140002001598400 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2017-03-27 20:19:15 140002001598400 [Note] InnoDB: GCC builtin __atomic_thread_fence() is used for memory barrier
2017-03-27 20:19:15 140002001598400 [Note] InnoDB: Compressed tables use zlib 1.2.8
2017-03-27 20:19:15 140002001598400 [Note] InnoDB: Using Linux native AIO
2017-03-27 20:19:15 140002001598400 [Note] InnoDB: Using SSE crc32 instructions
2017-03-27 20:19:15 140002001598400 [Note] InnoDB: Initializing buffer pool, size = 6.0G
2017-03-27 20:19:16 140002001598400 [Note] InnoDB: Completed initialization of buffer pool
2017-03-27 20:19:16 140002001598400 [ERROR] InnoDB: Only one log file found.
2017-03-27 20:19:16 140002001598400 [ERROR] Plugin 'InnoDB' init function returned error.
2017-03-27 20:19:16 140002001598400 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2017-03-27 20:19:16 140002001598400 [Note] Plugin 'FEEDBACK' is disabled.
2017-03-27 20:19:16 140002001598400 [ERROR] Unknown/unsupported storage engine: InnoDB
2017-03-27 20:19:16 140002001598400 [ERROR] Aborting

[mejsin (mejsin)]

and only this logfile exists:
-rw-r----- 1 mysql mysql 8388608 Mar 27 20:18 ib_logfile0

and not the second ib_logfile1

[Sergei Glushchenko (sergei.glushchenko)]

 --rebuild-indexes indicates that compact backups are used

[mejsin (mejsin)]

I remove the file:
 rm ib_logfile0

and restart, but see this in log now:
2017-03-27 20:26:40 139672482883520 [Note] InnoDB: Initializing buffer pool, size = 6.0G
2017-03-27 20:26:40 139672482883520 [Note] InnoDB: Completed initialization of buffer pool
2017-03-27 20:26:40 139672482883520 [Note] InnoDB: Setting log file ./ib_logfile101 size to 1024 MB
InnoDB: Progress in MB: 100 200 300 400 500 600 700 800 900 1000
2017-03-27 20:26:43 139672482883520 [Note] InnoDB: Setting log file ./ib_logfile1 size to 1024 MB
InnoDB: Progress in MB: 100 200 300 400 500 600 700 800 900 1000
2017-03-27 20:26:46 139672482883520 [Note] InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
2017-03-27 20:26:46 139672482883520 [Warning] InnoDB: New log files created, LSN=17321439244
2017-03-27 20:26:46 139672482883520 [Note] InnoDB: Highest supported file format is Barracuda.
2017-03-27 20:26:46 7f0808ba27c0 InnoDB: Error: page 7 log sequence number 18661007654
InnoDB: is in the future! Current system log sequence number 17321439756.
InnoDB: Your database may be corrupt or you may have copied the InnoDB
InnoDB: tablespace but not the InnoDB log files. See
InnoDB: http://dev.mysql.com/doc/refman/5.6/en/forcing-innodb-recovery.html
InnoDB: for more information.
2017-03-27 20:26:46 7f0808ba27c0 InnoDB: Error: page 2 log sequence number 18660851037

[mejsin (mejsin)]

tried removing --rebuild-indexes and that helped ;-) now restore works
is this a bug or ?

This ARG for xtrabackup is changed:
ARGS="--defaults-file=/<folder>/my.cnf --prepare ${LOG_ARG} --target-dir=/tmp/restore/ --rebuild-indexes --rebuild-threads=8"

to now:
ARGS="--defaults-file=/<folder>/my.cnf --prepare ${LOG_ARG} --target-dir=/tmp/restore/ --rebuild-threads=8"

so no rebuild is required, when we don't use compact ??