Using Percona sanity check

MySQL & MariaDB Percona XtraBackup
#1

Hi,

Using Percona innobackupex-1.5.1 to do my MySQL backups. The process i have is as below:

  1. Backup

/usr/bin/innobackupex-1.5.1 --user=username --password=password /alf_data/Backup/date '+%d%m%y'/2-MySQL/1-Percona-Backups > /alf_data/Backup/date '+%d%m%y'/logs/HotBackup.log

  1. Prepare

/usr/bin/innobackupex-1.5.1 --user=username --password=password–apply-log /alf_data/Backup/date '+%d%m%y'/2-MySQL/1-Percona-Backups/* > /alf_data/Backup/date '+%d%m%y'/logs/Recovery-Prep.log

There is only one directory in the prepare folder as its moved out of this folder when the cronjob ends.

When the prepare is carried out i get the following output message stating that the MySQL database wasnt shutdown correctly and something wrong with the log files.

“InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
110324 12:24:23 InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.”

I’ve uploaded the backup and prepare logs. Is this the right way of doing things?

Cheers, Ben

#2

Also tried using the extrabackup with the same commands:
Backup:
xtrabackup --backup --datadir=/opt/alfresco-3.4.d/mysql/data/ --target-dir=/alf_data/Backup/innotest

Prepare:
xtrabackup --prepare --target-dir=/alf_data/Backup/innotestxtrabackup

Prepare 2nd time for recovery:
xtrabackup --prepare --target-dir=/alf_data/Backup/innotestxtrabackup

This outputted roughly the same:

[root@localhost ~]# xtrabackup --backup --datadir=/opt/alfresco-3.4.d/mysql/data/ --target-dir=/alf_data/Backup/innotest
xtrabackup Ver 1.4 Rev 193 for 5.1.47 pc-linux-gnu (i686)
xtrabackup: uses posix_fadvise().
xtrabackup: cd to /opt/alfresco-3.4.d/mysql/data/
xtrabackup: Target instance is assumed as followings.
xtrabackup: innodb_data_home_dir = ./
xtrabackup: innodb_data_file_path = ibdata1:10M:autoextend
xtrabackup: innodb_log_group_home_dir = ./
xtrabackup: innodb_log_files_in_group = 2
xtrabackup: innodb_log_file_size = 5242880

log scanned up to (20780164)
Copying ./ibdata1
to /alf_data/Backup/innotest/ibdata1
…done
xtrabackup: The latest check point (for incremental): ‘20780164’

log scanned up to (20780164)
xtrabackup: Stopping log copying thread.
xtrabackup: Transaction log of lsn (20780164) to (20780164) was copied.
[root@localhost ~]# xtrabackup --prepare --target-dir=/alf_data/Backup/innotest
xtrabackup Ver 1.4 Rev 193 for 5.1.47 pc-linux-gnu (i686)
xtrabackup: cd to /alf_data/Backup/innotest
xtrabackup: This target seems to be not prepared yet.
xtrabackup: xtrabackup_logfile detected: size=2097152, start_lsn=(20780164)
xtrabackup: Temporary instance for recovery is set as followings.
xtrabackup: innodb_data_home_dir = ./
xtrabackup: innodb_data_file_path = ibdata1:10M:autoextend
xtrabackup: innodb_log_group_home_dir = ./
xtrabackup: innodb_log_files_in_group = 1
xtrabackup: innodb_log_file_size = 2097152
xtrabackup: Starting InnoDB instance for recovery.
xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
InnoDB: The InnoDB memory heap is disabled
InnoDB: Mutexes and rw_locks use InnoDB’s own implementation
InnoDB: Compressed tables use zlib 1.2.3
InnoDB: Warning: innodb_file_io_threads is deprecated. Please use innodb_read_io_threads and innodb_write_io_threads instead
110324 13:40:52 InnoDB: highest supported file format is Barracuda.
110324 13:40:54 Percona XtraDB (http://www.percona.com) 1.0.8-11.2 started; log sequence number 20780164

[notice (again)]
If you use binary log and don’t use any hack of group commit,
the binary log position seems to be:

xtrabackup: starting shutdown with innodb_fast_shutdown = 1
110324 13:40:54 InnoDB: Starting shutdown…
110324 13:40:59 InnoDB: Shutdown completed; log sequence number 20780164
[root@localhost ~]# xtrabackup --prepare --target-dir=/alf_data/Backup/innotest
xtrabackup Ver 1.4 Rev 193 for 5.1.47 pc-linux-gnu (i686)
xtrabackup: cd to /alf_data/Backup/innotest
xtrabackup: This target seems to be already prepared.
xtrabackup: notice: xtrabackup_logfile was already used to ‘–prepare’.
xtrabackup: Temporary instance for recovery is set as followings.
xtrabackup: innodb_data_home_dir = ./
xtrabackup: innodb_data_file_path = ibdata1:10M:autoextend
xtrabackup: innodb_log_group_home_dir = ./
xtrabackup: innodb_log_files_in_group = 2
xtrabackup: innodb_log_file_size = 5242880
xtrabackup: Starting InnoDB instance for recovery.
xtrabackup: Using 104857600 bytes for buffer pool (set by --use-memory parameter)
InnoDB: The InnoDB memory heap is disabled
InnoDB: Mutexes and rw_locks use InnoDB’s own implementation
InnoDB: Compressed tables use zlib 1.2.3
InnoDB: Warning: innodb_file_io_threads is deprecated. Please use innodb_read_io_threads and innodb_write_io_threads instead
110324 13:41:01 InnoDB: Log file ./ib_logfile0 did not exist: new to be created
InnoDB: Setting log file ./ib_logfile0 size to 5 MB
InnoDB: Database physically writes the file full: wait…
110324 13:41:01 InnoDB: Log file ./ib_logfile1 did not exist: new to be created
InnoDB: Setting log file ./ib_logfile1 size to 5 MB
InnoDB: Database physically writes the file full: wait…
110324 13:41:01 InnoDB: highest supported file format is Barracuda.
InnoDB: The log sequence number in ibdata files does not match
InnoDB: the log sequence number in the ib_logfiles!
110324 13:41:01 InnoDB: Database was not shut down normally!
InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files…
110324 13:41:02 Percona XtraDB (http://www.percona.com) 1.0.8-11.2 started; log sequence number 20780556

[notice (again)]
If you use binary log and don’t use any hack of group commit,
the binary log position seems to be:

xtrabackup: starting shutdown with innodb_fast_shutdown = 1
110324 13:41:02 InnoDB: Starting shutdown…
110324 13:41:07 InnoDB: Shutdown completed; log sequence number 20780556

can someone give this a quick once over for my own sanity. Been tinkering with this and other shell commands for the past week.

#3

i have the same issue where my node crashed and would not startup
giving this error in the innodb.prepare.log

InnoDB: Starting crash recovery.
InnoDB: Reading tablespace information from the .ibd files…
InnoDB: Last MySQL binlog file position 0 17886101, file name /var/log/mysql/mysql-bin.000082
121125 4:55:13 InnoDB: Waiting for the background threads to start
121125 4:55:14 Percona XtraDB (http://www.percona.com) 1.1.8-20.1 started; log sequence number 15744097292

[notice (again)]
If you use binary log and don’t use any hack of group commit,
the binary log position seems to be:
InnoDB: Last MySQL binlog file position 0 17886101, file name /var/log/mysql/mysql-bin.000082

xtrabackup: starting shutdown with innodb_fast_shutdown = 1
121125 4:55:58 InnoDB: Starting shutdown…
121125 4:55:59 InnoDB: Shutdown completed; log sequence number 15744097292
121125 04:55:59 innobackupex: completed OK!

please let me know if you have a solution

#4

Hi,

I have checked your attachments but it seems blank files for me. Can you again upload the files?

If your issue is that you are seeing “Crash Recovery” in the output message then It’s normal behavior while preparing backup. Because --apply-log is a crash recovery process itself, that how it works, it starts the crash recovery process to apply the redo logs copied during the backup in order to get a clean backup

Regards,

#5

Hi Mandm,

Your issue seems different. Can you provide commandline of taking backup and preparing backup with full log? It would be also good if you can create separate post for your issue.

MySQL, InnoDB, MariaDB and MongoDB are trademarks of their respective owners.
Copyright © 2006 - 2021 Percona LLC. All rights reserved.