# When full-backup using apply-log-only .it not work normally

**URL:** <https://forums.percona.com/t/when-full-backup-using-apply-log-only-it-not-work-normally/20201>\
**Category:** Percona XtraBackup\
**Tags:** mysql, percona\
**Created:** [February 20, 2023, 4:42pm UTC](https://forums.percona.com/t/when-full-backup-using-apply-log-only-it-not-work-normally/20201 "2023-02-20T16:42:24Z")\
**Posts on this page:** 15\
**Page:** 1

<div class="post-metadata">

**Author:** ![SunCheng](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/suncheng/32/9421_2.png) [@SunCheng](https://forums.percona.com/u/SunCheng)\
**Post date:** [February 20, 2023, 4:42pm UTC](https://forums.percona.com/t/when-full-backup-using-apply-log-only-it-not-work-normally/20201/1 "2023-02-20T16:42:25Z")

</div>

xtrabackup --defaults-file=/home/my3306/my.cnf -ubackupuser -p’backupser#123’ --socket=/home/my3306/run/mysql.sock --backup --target-dir=/home/backup/backupdir/base

xtrabackup --prepare --apply-log-only --target-dir=/home/backup/backupdir/base  
2023-02-21T00:28:42.856846+08:00 0 [Note] [MY-011825] [Xtrabackup] recognized server arguments: --innodb\_checksum\_algorithm=none --innodb\_log\_checksums=1 --innodb\_data\_file\_path=ibdata1:1G;ibdata2:32M:autoextend --innodb\_page\_size=16384 --innodb\_undo\_directory=./ --innodb\_undo\_tablespaces=2 --server-id=3648 --innodb\_log\_checksums=ON --innodb\_redo\_log\_encrypt=0 --innodb\_undo\_log\_encrypt=0  
2023-02-21T00:28:42.856941+08:00 0 [Note] [MY-011825] [Xtrabackup] recognized client arguments: --prepare=1 --apply-log-only=1 --target-dir=/home/backup/backupdir/base  
xtrabackup version 8.0.31-24 based on MySQL server 8.0.31 Linux (x86\_64) (revision id: f0754edb)  
2023-02-21T00:28:42.856967+08:00 0 [Note] [MY-011825] [Xtrabackup] cd to /home/backup/backupdir/base/  
2023-02-21T00:28:42.857009+08:00 0 [Note] [MY-011825] [Xtrabackup] This target seems to be not prepared yet.  
2023-02-21T00:28:42.863737+08:00 0 [Note] [MY-011825] [Xtrabackup] xtrabackup\_logfile detected: size=8388608, start\_lsn=(20536456)  
2023-02-21T00:28:42.864206+08:00 0 [Note] [MY-011825] [Xtrabackup] using the following InnoDB configuration for recovery:  
2023-02-21T00:28:42.864231+08:00 0 [Note] [MY-011825] [Xtrabackup] innodb\_data\_home\_dir = .  
2023-02-21T00:28:42.864244+08:00 0 [Note] [MY-011825] [Xtrabackup] innodb\_data\_file\_path = ibdata1:1G;ibdata2:32M:autoextend  
2023-02-21T00:28:42.864289+08:00 0 [Note] [MY-011825] [Xtrabackup] innodb\_log\_group\_home\_dir = .  
2023-02-21T00:28:42.864300+08:00 0 [Note] [MY-011825] [Xtrabackup] innodb\_log\_files\_in\_group = 1  
2023-02-21T00:28:42.864315+08:00 0 [Note] [MY-011825] [Xtrabackup] innodb\_log\_file\_size = 8388608  
2023-02-21T00:28:42.864527+08:00 0 [Note] [MY-011825] [Xtrabackup] inititialize\_service\_handles suceeded  
2023-02-21T00:28:42.864684+08:00 0 [Note] [MY-011825] [Xtrabackup] using the following InnoDB configuration for recovery:  
2023-02-21T00:28:42.864710+08:00 0 [Note] [MY-011825] [Xtrabackup] innodb\_data\_home\_dir = .  
2023-02-21T00:28:42.864716+08:00 0 [Note] [MY-011825] [Xtrabackup] innodb\_data\_file\_path = ibdata1:1G;ibdata2:32M:autoextend  
2023-02-21T00:28:42.864735+08:00 0 [Note] [MY-011825] [Xtrabackup] innodb\_log\_group\_home\_dir = .  
2023-02-21T00:28:42.864745+08:00 0 [Note] [MY-011825] [Xtrabackup] innodb\_log\_files\_in\_group = 1  
2023-02-21T00:28:42.864750+08:00 0 [Note] [MY-011825] [Xtrabackup] innodb\_log\_file\_size = 8388608  
2023-02-21T00:28:42.864760+08:00 0 [Note] [MY-011825] [Xtrabackup] Starting InnoDB instance for recovery.  
2023-02-21T00:28:42.864769+08:00 0 [Note] [MY-011825] [Xtrabackup] Using 104857600 bytes for buffer pool (set by --use-memory parameter)  
2023-02-21T00:28:42.864803+08:00 0 [Note] [MY-012932] [InnoDB] PUNCH HOLE support available  
2023-02-21T00:28:42.864819+08:00 0 [Note] [MY-012944] [InnoDB] Uses event mutexes  
2023-02-21T00:28:42.864825+08:00 0 [Note] [MY-012945] [InnoDB] GCC builtin \_\_atomic\_thread\_fence() is used for memory barrier  
2023-02-21T00:28:42.864839+08:00 0 [Note] [MY-012948] [InnoDB] Compressed tables use zlib 1.2.12  
2023-02-21T00:28:42.865024+08:00 0 [Note] [MY-012951] [InnoDB] Using hardware accelerated crc32 and polynomial multiplication.  
2023-02-21T00:28:42.865336+08:00 0 [Note] [MY-012203] [InnoDB] Directories to scan ‘./’  
2023-02-21T00:28:42.865366+08:00 0 [Note] [MY-012204] [InnoDB] Scanning ‘./’  
2023-02-21T00:28:42.866978+08:00 0 [Note] [MY-012208] [InnoDB] Completed space ID check of 9 files.  
2023-02-21T00:28:42.867386+08:00 0 [Note] [MY-012955] [InnoDB] Initializing buffer pool, total size = 128.000000M, instances = 1, chunk size =128.000000M

2023-02-21T00:28:42.874734+08:00 0 [Note] [MY-012957] [InnoDB] Completed initialization of buffer pool  
2023-02-21T00:28:42.877314+08:00 0 [Note] [MY-011952] [InnoDB] If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().  
2023-02-21T00:28:42.961091+08:00 0 [Note] [MY-013883] [InnoDB] The latest found checkpoint is at lsn = 20536456 in redo log file ./#innodb\_redo/#ib\_redo0.  
2023-02-21T00:28:42.961152+08:00 0 [Note] [MY-012560] [InnoDB] The log sequence number 19656859 in the system tablespace does not match the log sequence number 20536456 in the redo log files!  
2023-02-21T00:28:42.961165+08:00 0 [Note] [MY-012551] [InnoDB] Database was not shutdown normally!  
2023-02-21T00:28:42.961174+08:00 0 [Note] [MY-012552] [InnoDB] Starting crash recovery.  
2023-02-21T00:28:42.961288+08:00 0 [Note] [MY-013086] [InnoDB] Starting to parse redo log at lsn = 20536342, whereas checkpoint\_lsn = 20536456 and start\_lsn = 20536320  
2023-02-21T00:28:42.961315+08:00 0 [Note] [MY-012550] [InnoDB] Doing recovery: scanned up to log sequence number 20536456  
2023-02-21T00:28:42.972378+08:00 0 [Note] [MY-013083] [InnoDB] Log background threads are being started…  
2023-02-21T00:28:42.973112+08:00 0 [Note] [MY-012532] [InnoDB] Applying a batch of 0 redo log records …  
2023-02-21T00:28:42.973136+08:00 0 [Note] [MY-012535] [InnoDB] Apply batch completed!  
2023-02-21T00:28:43.073333+08:00 0 [Note] [MY-013252] [InnoDB] Using undo tablespace ‘./undo\_001’.  
2023-02-21T00:28:43.073772+08:00 0 [Note] [MY-013252] [InnoDB] Using undo tablespace ‘./undo\_002’.  
2023-02-21T00:28:43.074510+08:00 0 [Note] [MY-012910] [InnoDB] Opened 2 existing undo tablespaces.  
2023-02-21T00:28:43.074562+08:00 0 [Note] [MY-011980] [InnoDB] GTID recovery trx\_no: 2853  
2023-02-21T00:28:43.140002+08:00 0 [Note] [MY-013776] [InnoDB] Parallel initialization of rseg complete  
2023-02-21T00:28:43.140044+08:00 0 [Note] [MY-013777] [InnoDB] Time taken to initialize rseg using 4 thread: 65484 ms.  
2023-02-21T00:28:43.140105+08:00 0 [Note] [MY-012923] [InnoDB] Creating shared tablespace for temporary tables  
2023-02-21T00:28:43.140156+08:00 0 [Note] [MY-012265] [InnoDB] Setting file ‘./ibtmp1’ size to 12 MB. Physically writing the file full; Please wait …  
2023-02-21T00:28:43.165639+08:00 0 [Note] [MY-012266] [InnoDB] File ‘./ibtmp1’ size is now 12 MB.  
2023-02-21T00:28:43.165782+08:00 0 [Note] [MY-013627] [InnoDB] Scanning temp tablespace dir:‘./#innodb\_temp/’  
2023-02-21T00:28:43.175421+08:00 0 [Note] [MY-013018] [InnoDB] Created 128 and tracked 128 new rollback segment(s) in the temporary tablespace. 128 are now active.  
2023-02-21T00:28:43.175605+08:00 0 [Note] [MY-012976] [InnoDB] 8.0.31 started; log sequence number 20536466  
2023-02-21T00:28:43.175981+08:00 0 [Warning] [MY-012091] [InnoDB] Allocated tablespace ID 1 for sys/sys\_config, old maximum was 0  
2023-02-21T00:28:43.206337+08:00 0 [Note] [MY-011825] [Xtrabackup] starting shutdown with innodb\_fast\_shutdown = 1  
2023-02-21T00:28:43.206420+08:00 0 [Note] [MY-012330] [InnoDB] FTS optimize thread exiting.  
2023-02-21T00:28:44.206275+08:00 0 [Note] [MY-013072] [InnoDB] Starting shutdown…  
2023-02-21T00:28:44.210134+08:00 0 [Note] [MY-013084] [InnoDB] Log background threads are being closed…  
2023-02-21T00:28:44.222000+08:00 0 [Note] [MY-012980] [InnoDB] Shutdown completed; log sequence number 20536466  
2023-02-21T00:28:44.224233+08:00 0 [Note] [MY-011825] [Xtrabackup] completed OK!

the message “Database was not shutdown normally!” explain the apply-log-only is ignored ? how to deal with it. thanks.

---

<div class="post-metadata">

**Author:** ![Pep\_Pla](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/pep_pla/32/9735_2.png) [@Pep\_Pla](https://forums.percona.com/u/Pep_Pla)\
**Post date:** [February 20, 2023, 5:08pm UTC](https://forums.percona.com/t/when-full-backup-using-apply-log-only-it-not-work-normally/20201/2 "2023-02-20T17:08:49Z")

</div>

Hi @SunCheng

Thank you for being an active member of our community.

Not sure if I understood your problem. The “Database was not shutdown normally” is a standard message during the `prepare` stage. It is not an error. It is just informative.

Are you restoring incremental backups? If you are not, you should not use the `--apply-only option`.

Thanks

Pep

---

<div class="post-metadata">

**Author:** ![SunCheng](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/suncheng/32/9421_2.png) [@SunCheng](https://forums.percona.com/u/SunCheng)\
**Post date:** [February 21, 2023, 12:43am UTC](https://forums.percona.com/t/when-full-backup-using-apply-log-only-it-not-work-normally/20201/3 "2023-02-21T00:43:53Z")

</div>

i will do incremental restore.

xtrabackup --defaults-file=/home/my3306/my.cnf -ubackupuser -p’backupser#123’ --socket=/home/my3306/run/mysql.sock --backup --target-dir=/home/backup/backupdir/inc1 --incremental-basedir=/home/backup/backupdir/base

xtrabackup --prepare --target-dir=/home/backup/backupdir/base --incremental-basedir=/home/backup/backupdir/inc1

after i did the full-backup with --prepare andn --apply-log-only. then incremental resotre --prepare . the lsn not equal to xtrabackup\_checkpoints’s to\_lsn . it’s report "xtrabackup\_logfile was already used to ‘–prepare’. " so i assume that the full-backup --apply-log-only is not work.

---

<div class="post-metadata">

**Author:** ![SunCheng](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/suncheng/32/9421_2.png) [@SunCheng](https://forums.percona.com/u/SunCheng)\
**Post date:** [February 21, 2023, 12:59am UTC](https://forums.percona.com/t/when-full-backup-using-apply-log-only-it-not-work-normally/20201/4 "2023-02-21T00:59:43Z")

</div>

xtrabackup --prepare --target-dir=/home/backup/backupdir/base --incremental-basedir=/home/backup/backupdir/inc1

2023-02-21T08:42:48.867873+08:00 0 [Note] [MY-011825] [Xtrabackup] recognized server arguments: --innodb\_checksum\_algorithm=none --innodb\_log\_checksums=1 --innodb\_data\_file\_path=ibdata1:1G;ibdata2:32M:autoextend --innodb\_page\_size=16384 --innodb\_undo\_directory=./ --innodb\_undo\_tablespaces=2 --server-id=3648 --innodb\_log\_checksums=ON --innodb\_redo\_log\_encrypt=0 --innodb\_undo\_log\_encrypt=0  
2023-02-21T08:42:48.867978+08:00 0 [Note] [MY-011825] [Xtrabackup] recognized client arguments: --prepare=1 --target-dir=/home/backup/backupdir/base --incremental-basedir=/home/backup/backupdir/inc1  
xtrabackup version 8.0.31-24 based on MySQL server 8.0.31 Linux (x86\_64) (revision id: f0754edb)  
2023-02-21T08:42:48.868005+08:00 0 [Note] [MY-011825] [Xtrabackup] cd to /home/backup/backupdir/base/  
2023-02-21T08:42:48.868059+08:00 0 [Note] [MY-011825] [Xtrabackup] This target seems to be already prepared with --apply-log-only.  
2023-02-21T08:42:48.868646+08:00 0 [Note] [MY-011825] [Xtrabackup] xtrabackup\_logfile was already used to ‘–prepare’.  
2023-02-21T08:42:48.868994+08:00 0 [Note] [MY-011825] [Xtrabackup] using the following InnoDB configuration for recovery:  
2023-02-21T08:42:48.869015+08:00 0 [Note] [MY-011825] [Xtrabackup] innodb\_data\_home\_dir = .  
2023-02-21T08:42:48.869028+08:00 0 [Note] [MY-011825] [Xtrabackup] innodb\_data\_file\_path = ibdata1:1G;ibdata2:32M:autoextend  
2023-02-21T08:42:48.869090+08:00 0 [Note] [MY-011825] [Xtrabackup] innodb\_log\_group\_home\_dir = .  
2023-02-21T08:42:48.869103+08:00 0 [Note] [MY-011825] [Xtrabackup] innodb\_log\_files\_in\_group = 2  
2023-02-21T08:42:48.869115+08:00 0 [Note] [MY-011825] [Xtrabackup] innodb\_log\_file\_size = 50331648  
2023-02-21T08:42:48.869332+08:00 0 [Note] [MY-011825] [Xtrabackup] inititialize\_service\_handles suceeded  
2023-02-21T08:42:48.869509+08:00 0 [Note] [MY-011825] [Xtrabackup] using the following InnoDB configuration for recovery:  
2023-02-21T08:42:48.869527+08:00 0 [Note] [MY-011825] [Xtrabackup] innodb\_data\_home\_dir = .  
2023-02-21T08:42:48.869533+08:00 0 [Note] [MY-011825] [Xtrabackup] innodb\_data\_file\_path = ibdata1:1G;ibdata2:32M:autoextend  
2023-02-21T08:42:48.869551+08:00 0 [Note] [MY-011825] [Xtrabackup] innodb\_log\_group\_home\_dir = .  
2023-02-21T08:42:48.869559+08:00 0 [Note] [MY-011825] [Xtrabackup] innodb\_log\_files\_in\_group = 2  
2023-02-21T08:42:48.869581+08:00 0 [Note] [MY-011825] [Xtrabackup] innodb\_log\_file\_size = 50331648  
2023-02-21T08:42:48.869589+08:00 0 [Note] [MY-011825] [Xtrabackup] Starting InnoDB instance for recovery.  
2023-02-21T08:42:48.869597+08:00 0 [Note] [MY-011825] [Xtrabackup] Using 104857600 bytes for buffer pool (set by --use-memory parameter)  
2023-02-21T08:42:48.869635+08:00 0 [Note] [MY-012932] [InnoDB] PUNCH HOLE support available  
2023-02-21T08:42:48.869654+08:00 0 [Note] [MY-012944] [InnoDB] Uses event mutexes  
2023-02-21T08:42:48.869665+08:00 0 [Note] [MY-012945] [InnoDB] GCC builtin \_\_atomic\_thread\_fence() is used for memory barrier  
2023-02-21T08:42:48.869686+08:00 0 [Note] [MY-012948] [InnoDB] Compressed tables use zlib 1.2.12  
2023-02-21T08:42:48.869873+08:00 0 [Note] [MY-012951] [InnoDB] Using hardware accelerated crc32 and polynomial multiplication.  
2023-02-21T08:42:48.870218+08:00 0 [Note] [MY-012203] [InnoDB] Directories to scan ‘./’  
2023-02-21T08:42:48.870250+08:00 0 [Note] [MY-012204] [InnoDB] Scanning ‘./’  
2023-02-21T08:42:48.870841+08:00 0 [Note] [MY-012208] [InnoDB] Completed space ID check of 9 files.  
2023-02-21T08:42:48.871288+08:00 0 [Note] [MY-012955] [InnoDB] Initializing buffer pool, total size = 128.000000M, instances = 1, chunk size =128.000000M  
2023-02-21T08:42:48.878351+08:00 0 [Note] [MY-012957] [InnoDB] Completed initialization of buffer pool  
2023-02-21T08:42:48.880727+08:00 0 [Note] [MY-011952] [InnoDB] If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().  
2023-02-21T08:42:48.950195+08:00 0 [Note] [MY-011825] [InnoDB] Creating redo log file at ./#innodb\_redo/#ib\_redo0\_tmp with file\_id 0 with size 33554432 bytes  
2023-02-21T08:42:48.951734+08:00 0 [Note] [MY-011825] [InnoDB] Renaming redo log file from ./#innodb\_redo/#ib\_redo0\_tmp to ./#innodb\_redo/#ib\_redo0  
2023-02-21T08:42:48.952582+08:00 0 [Note] [MY-012893] [InnoDB] New redo log files created, LSN=20536466  
2023-02-21T08:42:48.953208+08:00 0 [Note] [MY-013883] [InnoDB] The latest found checkpoint is at lsn = 20536844 in redo log file ./#innodb\_redo/#ib\_redo0.  
2023-02-21T08:42:48.953314+08:00 0 [Note] [MY-013086] [InnoDB] Starting to parse redo log at lsn = 20536844, whereas checkpoint\_lsn = 20536844 and start\_lsn = 20536832  
2023-02-21T08:42:48.954525+08:00 0 [Note] [MY-013083] [InnoDB] Log background threads are being started…  
2023-02-21T08:42:48.955288+08:00 0 [Note] [MY-012532] [InnoDB] Applying a batch of 0 redo log records …  
2023-02-21T08:42:48.955315+08:00 0 [Note] [MY-012535] [InnoDB] Apply batch completed!  
2023-02-21T08:42:48.955466+08:00 0 [Note] [MY-013084] [InnoDB] Log background threads are being closed…  
2023-02-21T08:42:48.956831+08:00 0 [Note] [MY-013041] [InnoDB] Resizing redo log from 32M to 1024M (LSN=20536844) synchronously. If this takes too long, consider starting the server with large --innodb\_redo\_log\_capacity, and resizing the redo log online using SET.  
2023-02-21T08:42:48.957760+08:00 0 [Note] [MY-012968] [InnoDB] Starting to delete and rewrite redo log files.  
2023-02-21T08:42:48.957807+08:00 0 [Note] [MY-011825] [InnoDB] Removing redo log file: ./#innodb\_redo/#ib\_redo0  
2023-02-21T08:42:49.029516+08:00 0 [Note] [MY-011825] [InnoDB] Creating redo log file at ./#innodb\_redo/#ib\_redo0\_tmp with file\_id 0 with size 33554432 bytes  
2023-02-21T08:42:49.031153+08:00 0 [Note] [MY-011825] [InnoDB] Renaming redo log file from ./#innodb\_redo/#ib\_redo0\_tmp to ./#innodb\_redo/#ib\_redo0  
2023-02-21T08:42:49.031873+08:00 0 [Note] [MY-012893] [InnoDB] New redo log files created, LSN=20537356  
2023-02-21T08:42:49.031920+08:00 0 [Note] [MY-013083] [InnoDB] Log background threads are being started…  
2023-02-21T08:42:49.032681+08:00 0 [Note] [MY-013252] [InnoDB] Using undo tablespace ‘./undo\_001’.  
2023-02-21T08:42:49.049421+08:00 0 [Note] [MY-013252] [InnoDB] Using undo tablespace ‘./undo\_002’.  
2023-02-21T08:42:49.062610+08:00 0 [Note] [MY-012910] [InnoDB] Opened 2 existing undo tablespaces.  
2023-02-21T08:42:49.062668+08:00 0 [Note] [MY-011980] [InnoDB] GTID recovery trx\_no: 2853  
2023-02-21T08:42:49.067429+08:00 0 [Note] [MY-013776] [InnoDB] Parallel initialization of rseg complete  
2023-02-21T08:42:49.067466+08:00 0 [Note] [MY-013777] [InnoDB] Time taken to initialize rseg using 4 thread: 4805 ms.  
2023-02-21T08:42:49.068477+08:00 0 [Note] [MY-012255] [InnoDB] Removed temporary tablespace data file: “ibtmp1”  
2023-02-21T08:42:49.068501+08:00 0 [Note] [MY-012923] [InnoDB] Creating shared tablespace for temporary tables  
2023-02-21T08:42:49.068538+08:00 0 [Note] [MY-012265] [InnoDB] Setting file ‘./ibtmp1’ size to 12 MB. Physically writing the file full; Please wait …  
2023-02-21T08:42:49.086854+08:00 0 [Note] [MY-012266] [InnoDB] File ‘./ibtmp1’ size is now 12 MB.  
2023-02-21T08:42:49.086989+08:00 0 [Note] [MY-013627] [InnoDB] Scanning temp tablespace dir:‘./#innodb\_temp/’  
2023-02-21T08:42:49.096344+08:00 0 [Note] [MY-013018] [InnoDB] Created 128 and tracked 128 new rollback segment(s) in the temporary tablespace. 128 are now active.  
2023-02-21T08:42:49.096530+08:00 0 [Note] [MY-012976] [InnoDB] 8.0.31 started; log sequence number 20537366  
2023-02-21T08:42:49.108635+08:00 0 [Warning] [MY-012091] [InnoDB] Allocated tablespace ID 1 for sys/sys\_config, old maximum was 0  
2023-02-21T08:42:49.178479+08:00 0 [Note] [MY-011825] [Xtrabackup] starting shutdown with innodb\_fast\_shutdown = 1  
2023-02-21T08:42:49.178541+08:00 0 [Note] [MY-012330] [InnoDB] FTS optimize thread exiting.  
2023-02-21T08:42:50.178441+08:00 0 [Note] [MY-013072] [InnoDB] Starting shutdown…  
2023-02-21T08:42:50.182401+08:00 0 [Note] [MY-013084] [InnoDB] Log background threads are being closed…  
2023-02-21T08:42:50.195789+08:00 0 [Note] [MY-012980] [InnoDB] Shutdown completed; log sequence number 20537366  
2023-02-21T08:42:50.198121+08:00 0 [Note] [MY-011825] [Xtrabackup] completed OK!

---

<div class="post-metadata">

**Author:** ![Pep\_Pla](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/pep_pla/32/9735_2.png) [@Pep\_Pla](https://forums.percona.com/u/Pep_Pla)\
**Post date:** [February 21, 2023, 7:07am UTC](https://forums.percona.com/t/when-full-backup-using-apply-log-only-it-not-work-normally/20201/5 "2023-02-21T07:07:29Z")

</div>

Hi @SunCheng

Could you post the exact steps that you followed?

Please, do not post full logs, if you feel that they are required, edit them to post the relevant parts only.

Thank you!

Pep

---

<div class="post-metadata">

**Author:** ![SunCheng](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/suncheng/32/9421_2.png) [@SunCheng](https://forums.percona.com/u/SunCheng)\
**Post date:** [February 21, 2023, 9:01am UTC](https://forums.percona.com/t/when-full-backup-using-apply-log-only-it-not-work-normally/20201/6 "2023-02-21T09:01:53Z")

</div>

#########FULL BACKUP###############  
xtrabackup --defaults-file=/home/my3306/my.cnf -uroot -p’pAssWord123’ --socket=/home/my3306/run/mysql.sock --backup --target-dir=/home/backup/backupdir/full

######LOGS  
Transaction log of lsn (20544705) to (20544715) was copied.  
######XINFO  
binlog\_pos = filename ‘mysql-bin.000052’, position ‘193’, GTID of the last change ‘0f037394-ac37-11ed-8b43-5254bb991234:1-106’  
innodb\_from\_lsn = 0  
innodb\_to\_lsn = 20544705

#########INCREMENTAL BACKUP###############  
xtrabackup --defaults-file=/home/my3306/my.cnf -uroot -p’pAssWord123’ --socket=/home/my3306/run/mysql.sock --backup --target-dir=/home/backup/backupdir/inc1 --incremental-basedir=/home/backup/backupdir/full  
######LOGS  
[Xtrabackup] incremental backup from 20544705 is enabled.  
[Xtrabackup]Transaction log of lsn (20545575) to (20546750) was copied.  
######XINFO  
binlog\_pos = filename ‘mysql-bin.000053’, position ‘193’, GTID of the last change ‘0f037394-ac37-11ed-8b43-5254bb991234:1-107’  
innodb\_from\_lsn = 20544705  
innodb\_to\_lsn = 20545575

######## above bakcup is ok #############

#########RESTORE ###############  
xtrabackup --prepare --apply-log-only --target-dir=/home/backup/backupdir/full  
[Xtrabackup] This target seems to be not prepared yet.  
[InnoDB] The log sequence number 19656859 in the system tablespace does not match the log sequence number 20544705 in the redo log files!  
[InnoDB] Database was not shutdown normally!  
[InnoDB] Starting crash recovery.  
[InnoDB] Starting to parse redo log at lsn = 20544543, whereas checkpoint\_lsn = 20544705 and start\_lsn = 20544512  
[InnoDB] Doing recovery: scanned up to log sequence number 20544705  
[InnoDB] Log background threads are being started…  
[InnoDB] Applying a batch of 0 redo log records …  
[InnoDB] Apply batch completed!  
[InnoDB] Using undo tablespace ‘./undo\_001’.  
[InnoDB] Using undo tablespace ‘./undo\_002’.  
[InnoDB] Opened 2 existing undo tablespaces.  
[InnoDB] Shutdown completed; log sequence number 20544715 \<\<\<\<\<\<not equal to xinfo-to\_lsn

xtrabackup --prepare -target-dir=/home/backup/backupdir/full --incremental-basedir=/home/backup/backupdir/inc1

[Xtrabackup] This target seems to be already prepared with --apply-log-only.  
[Xtrabackup] xtrabackup\_logfile was already used to ‘–prepare’. \<\<\<\< report already --prepare  
[InnoDB] Log background threads are being closed…  
[InnoDB] Shutdown completed; log sequence number 20545558 \<\<\<\< not equal to XINFO-to\_lsn

---

<div class="post-metadata">

**Author:** ![SunCheng](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/suncheng/32/9421_2.png) [@SunCheng](https://forums.percona.com/u/SunCheng)\
**Post date:** [February 21, 2023, 9:04am UTC](https://forums.percona.com/t/when-full-backup-using-apply-log-only-it-not-work-normally/20201/7 "2023-02-21T09:04:05Z")

</div>

rsync -avrP /home/backup/backupdir/full/ /home/my3307/data/  
chown -R mysql:mysql /home/my3307

/opt/mysql/bin/mysqld\_safe --defaults-file=/home/my3307/my.cnf &

mysql -uroot -p’pAssWord123’ --socket=/home/my3307/run/mysql.sock

above ops to startup database. select table the rows is not same.  
the last row is insert before incremental backup.

mysql\> select \* from inc1;  
±—±------+  
| id | name |  
±—±------+  
| 10 | inc1 |  
| 11 | inc11 |  
±—±------+

mysql\> select \* from testdb.inc1;  
±—±-----+  
| id | name |  
±—±-----+  
| 10 | inc1 |  
±—±-----+

---

<div class="post-metadata">

**Author:** ![Pep\_Pla](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/pep_pla/32/9735_2.png) [@Pep\_Pla](https://forums.percona.com/u/Pep_Pla)\
**Post date:** [February 21, 2023, 12:14pm UTC](https://forums.percona.com/t/when-full-backup-using-apply-log-only-it-not-work-normally/20201/8 "2023-02-21T12:14:42Z")

</div>

> xtrabackup --prepare -target-dir=/home/backup/backupdir/full --incremental-basedir=/home/backup/backupdir/inc1

Not sure if this is a copy&paste error, but `-target-dir` has a missing `-`.

---

<div class="post-metadata">

**Author:** ![SunCheng](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/suncheng/32/9421_2.png) [@SunCheng](https://forums.percona.com/u/SunCheng)\
**Post date:** [February 21, 2023, 1:25pm UTC](https://forums.percona.com/t/when-full-backup-using-apply-log-only-it-not-work-normally/20201/9 "2023-02-21T13:25:10Z")

</div>

copy error.  
xtrabackup --prepare --target-dir=/home/backup/backupdir/full --incremental-basedir=/home/backup/backupdir/inc1

---

<div class="post-metadata">

**Author:** ![SunCheng](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/suncheng/32/9421_2.png) [@SunCheng](https://forums.percona.com/u/SunCheng)\
**Post date:** [February 21, 2023, 1:26pm UTC](https://forums.percona.com/t/when-full-backup-using-apply-log-only-it-not-work-normally/20201/10 "2023-02-21T13:26:31Z")

</div>

if you have time. you can test it.

i can not success.

---

<div class="post-metadata">

**Author:** ![Pep\_Pla](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/pep_pla/32/9735_2.png) [@Pep\_Pla](https://forums.percona.com/u/Pep_Pla)\
**Post date:** [February 21, 2023, 2:11pm UTC](https://forums.percona.com/t/when-full-backup-using-apply-log-only-it-not-work-normally/20201/11 "2023-02-21T14:11:13Z")

</div>

I’ll try to test it, but I may need a few days to test.

Could you tell me the operating system version/distribution/cpu family?

Are you using version 8.0.31 both for the database and xtrabackup?

---

<div class="post-metadata">

**Author:** ![SunCheng](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/suncheng/32/9421_2.png) [@SunCheng](https://forums.percona.com/u/SunCheng)\
**Post date:** [February 21, 2023, 2:41pm UTC](https://forums.percona.com/t/when-full-backup-using-apply-log-only-it-not-work-normally/20201/12 "2023-02-21T14:41:01Z")

</div>

Could you tell me the operating system version/distribution/cpu family?  
Os is openeuler, 20.03, X86 same as centos 7

Are you using version 8.0.31 both for the database and xtrabackup?  
Yes, both of them is 8.0.31.

---

<div class="post-metadata">

**Author:** ![SunCheng](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/suncheng/32/9421_2.png) [@SunCheng](https://forums.percona.com/u/SunCheng)\
**Post date:** [February 21, 2023, 3:28pm UTC](https://forums.percona.com/t/when-full-backup-using-apply-log-only-it-not-work-normally/20201/13 "2023-02-21T15:28:55Z")

</div>

I test on redhat 7.6 , it has same result.

[root@mysql1 backup]# cat /etc/redhat-release  
Red Hat Enterprise Linux Server release 7.6 (Maipo)

[InnoDB] Shutdown completed; log sequence number 19413992  
innodb\_from\_lsn = 0  
innodb\_to\_lsn = 19413982

---

<div class="post-metadata">

**Author:** ![SunCheng](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/suncheng/32/9421_2.png) [@SunCheng](https://forums.percona.com/u/SunCheng)\
**Post date:** [February 21, 2023, 4:11pm UTC](https://forums.percona.com/t/when-full-backup-using-apply-log-only-it-not-work-normally/20201/14 "2023-02-21T16:11:58Z")

</div>

I have found the problem, apply incremental backup uses incremental-basedir option, but the correct option is incremental-dir.

thanks for your patience.

---

<div class="post-metadata">

**Author:** ![Pep\_Pla](https://sea1.discourse-cdn.com/flex019/user_avatar/forums.percona.com/pep_pla/32/9735_2.png) [@Pep\_Pla](https://forums.percona.com/u/Pep_Pla)\
**Post date:** [February 22, 2023, 8:45am UTC](https://forums.percona.com/t/when-full-backup-using-apply-log-only-it-not-work-normally/20201/15 "2023-02-22T08:45:26Z")

</div>

Thank you @SunCheng !