I am unable to `innobackupex --apply-log --export` for any backup I made

tdc · November 22, 2022, 10:23pm

Hello there,

I’m totally new to xtrabackup. We have some big databases and it takes a lot of time to restore them from mysqldump backups locally. xtrabackup should be much faster, so I have installed percona-xtrabackup-24-2.4.26-1.el7.x86_64. The issue that I have at the moment is that I can’t prepare and export the backup, so it’s ready to be imported locally. I have tried to export multiple databases multiple times and every time I try to prep and export there is an error. Different error every time. For example the following errors are by trying to prep and export backups of the same database.

xtrabackup: export metadata of table 'demouk/FTS_000000000000a2e2_0000000000019077_INDEX_2' to file `./demouk/FTS_000000000000a2e2_0000000000019077_INDEX_2.exp` (1 indexes)
xtrabackup:     name=FTS_INDEX_TABLE_IND, id.low=102521, page=3
[FATAL] InnoDB: Unknown data type number 97
2022-11-22 21:16:49 0x7fa327e9f880  InnoDB: Assertion failure in thread 140338726041728 in file ut0ut.cc line 919

xtrabackup: export metadata of table 'demouk/FTS_000000000000a2e2_0000000000019077_INDEX_2' to file `./demouk/FTS_000000000000a2e2_0000000000019077_INDEX_2.exp` (1 indexes)
xtrabackup:     name=FTS_INDEX_TABLE_IND, id.low=102521, page=3
[FATAL] InnoDB: Unknown data type number 0
2022-11-22 21:33:00 0x7f86d7661880  InnoDB: Assertion failure in thread 140217116137600 in file ut0ut.cc line 919

xtrabackup: export metadata of table 'demouk/jobbags' to file `./demouk/jobbags.exp` (15 indexes)
xtrabackup:     name=PRIMARY, id.low=88475, page=3
xtrabackup:     name=FTS_DOC_ID_INDEX, id.low=88481, page=4
xtrabackup:     name=jobbags_client_id_idx, id.low=88482, page=5
xtrabackup:     name=jobbags_cust_id_idx, id.low=88483, page=6
xtrabackup:     name=jobbags_custmem_id_idx, id.low=88484, page=8
xtrabackup:     name=jobbags_custref_idx, id.low=88485, page=9
xtrabackup:     name=jobbags_clientref_idx, id.low=88486, page=10
xtrabackup:     name=jobbags_jobPO_idx, id.low=88487, page=12
xtrabackup:     name=jobbags_status_idx, id.low=88488, page=13
xtrabackup:     name=jobbags_flags_idx, id.low=88489, page=14
xtrabackup:     name=jobbag_create_date_index, id.low=88490, page=15
xtrabackup:     name=jobbags_basket_idx, id.low=88491, page=17
xtrabackup:     name=jobbags_vat_code_fk, id.low=88492, page=18
xtrabackup:     name=jobbags_modified_idx, id.low=88493, page=19
xtrabackup:     name=jobbags_text_idx, id.low=88494, page=4294967295
22:10:55 UTC - xtrabackup got signal 11 ;

I have reported the first one I have experienced in JIRA but most probably it’s not a problem with xtrabackup itself but something locally. Did someone else have experienced something like this?

P.S. The database server is a slave server but I didn’t see anything in the docs to suggest I need to add some specific options.

matthewb · November 23, 2022, 12:37am

Hey @tdc,
Just to confirm, you are using Xtrabackup 2.4 on MySQL 5.7, correct? And this is the pattern you are following?

xtrabackup --backup --parallel 4 --target-dir /path/to/backup/
xtrabackup --prepare --target-dir /path/to/backup
systemctl stop mysql
rm -rf /var/lib/mysql/*
xtrabackup --copy-back --target-dir /path/to/backup/
chown -R mysql:mysql /var/lib/mysql
systemctl start mysql

That process is an abbreviated version of what I teach in Percona’s MySQL Operations class for backup and recovery.

tdc · November 23, 2022, 9:34am

Thank you @matthewb I have tried and have reported the error from it as a JIRA ticket, because I believed it was an issue.

xtrabackup --backup --datadir=/var/lib/mysql --target-dir=./test --databases="demouk"
xtrabackup --prepare --export --target-dir=./test

After this I have tried the same thing with different databases and multiple backups. The logs I have provided are from the following commands

innobackupex --databases="demouk" ./test
innobackupex --apply-log --export test/2022-11-22_22-08-31/

I have switched to innobackupex hoping that the script will make checks and apply additional parameters depending on the database and its configuration. However it didn’t help.

Version info is as follow

[user@db04 user_home]# mysql --version
mysql  Ver 14.14 Distrib 5.7.35-38, for Linux (x86_64) using  6.2
[user@db04 user_home]# xtrabackup --version
xtrabackup: recognized server arguments: --datadir=/var/lib/mysql --server-id=4 --log_bin=db04-bin --open_files_limit=65535 --innodb_buffer_pool_size=5861M --innodb_file_per_table=1 --innodb_flush_method=O_DIRECT --innodb_io_capacity=10000 --innodb_log_buffer_size=4M --innodb_log_file_size=256M --innodb_page_size=4096
xtrabackup version 2.4.26 based on MySQL server 5.7.35 Linux (x86_64) (revision id: 19de43b)
[user@db04 user_home]# innobackupex --version
xtrabackup: recognized server arguments: --datadir=/var/lib/mysql --server-id=4 --log_bin=db04-bin --open_files_limit=65535 --innodb_buffer_pool_size=5861M --innodb_file_per_table=1 --innodb_flush_method=O_DIRECT --innodb_io_capacity=10000 --innodb_log_buffer_size=4M --innodb_log_file_size=256M --innodb_page_size=4096
innobackupex version 2.4.26 Linux (x86_64) (revision id: 19de43b)

Marcelo_Altmann · November 23, 2022, 11:31am

Hi there.

The issue seems to be happening on a Full Text for the same table always.
Can you check which table it belongs to and try to create this same table on a test instance and validate if it still failing?

To find out the table:

SELECT table_id, name, space from INFORMATION_SCHEMA.INNODB_SYS_TABLES WHERE table_id = 41698;

Lets see if you can reproduce it only with table structure.

tdc · November 23, 2022, 4:43pm

@Marcelo_Altmann , exporting only the affected table with

innobackupex --databases="demouk.catalogueitems" ./test
innobackupex --apply-log --export test/2022-11-23_16-23-06/

produced the following error

...
...
InnoDB: Creating shared tablespace for temporary tables
InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
InnoDB: File './ibtmp1' size is now 12 MB.
InnoDB: 96 redo rollback segment(s) found. 1 redo rollback segment(s) are active.
InnoDB: 32 non-redo rollback segment(s) are active.
InnoDB: page_cleaner: 1000ms intended loop took 16108ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)
InnoDB: 5.7.35 started; log sequence number 253909627151
xtrabackup: export option is specified.
xtrabackup: export metadata of table 'demouk/catalogueitems' to file `./demouk/catalogueitems.exp` (9 indexes)
xtrabackup:     name=PRIMARY, id.low=102506, page=3
xtrabackup:     name=FTS_DOC_ID_INDEX, id.low=102512, page=4
xtrabackup:     name=catalogue_object_idx, id.low=102513, page=5
xtrabackup:     name=catalogue_search_idx, id.low=102514, page=6
xtrabackup:     name=catalogues_modified_idx, id.low=102515, page=8
xtrabackup:     name=catalogueitems_checklist_fk, id.low=102516, page=9
xtrabackup:     name=catalogueitems_tax_code_fk, id.low=102517, page=10
xtrabackup:     name=catalogueitems_matgroup_idx, id.low=102518, page=12
xtrabackup:     name=catalogueitems_text, id.low=102519, page=4294967295
InnoDB: xtrabackup: Last MySQL binlog file position 89684162, file name db04-bin.000738

xtrabackup: starting shutdown with innodb_fast_shutdown = 0
2022-11-23 16:23:44 0x7f8e13fff700  InnoDB: Assertion failure in thread 140248197625600 in file pars0pars.cc line 830
InnoDB: Failing assertion: sym_node->table != NULL
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.
16:23:44 UTC - xtrabackup got signal 6 ;

I have created a new database and have created the table using the exact structure.

innobackupex --databases="xbackup.catalogueitems" ./test
innobackupex --apply-log --export test/2022-11-23_16-23-06/

and the error is

...
...
InnoDB: Creating shared tablespace for temporary tables
InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
InnoDB: File './ibtmp1' size is now 12 MB.
InnoDB: 96 redo rollback segment(s) found. 1 redo rollback segment(s) are active.
InnoDB: 32 non-redo rollback segment(s) are active.
InnoDB: 5.7.35 started; log sequence number 253910756578
InnoDB: page_cleaner: 1000ms intended loop took 18515ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)
xtrabackup: export option is specified.
xtrabackup: export metadata of table 'xbackup/catalogueitems' to file `./xbackup/catalogueitems.exp` (9 indexes)
xtrabackup:     name=PRIMARY, id.low=102536, page=3
xtrabackup:     name=FTS_DOC_ID_INDEX, id.low=102542, page=4
xtrabackup:     name=catalogue_object_idx, id.low=102543, page=5
xtrabackup:     name=catalogue_search_idx, id.low=102544, page=6
xtrabackup:     name=catalogues_modified_idx, id.low=102545, page=8
xtrabackup:     name=catalogueitems_checklist_fk, id.low=102546, page=9
xtrabackup:     name=catalogueitems_tax_code_fk, id.low=102547, page=10
xtrabackup:     name=catalogueitems_matgroup_idx, id.low=102548, page=12
xtrabackup:     name=catalogueitems_text, id.low=102549, page=4294967295
InnoDB: xtrabackup: Last MySQL binlog file position 90506498, file name db04-bin.000738

xtrabackup: starting shutdown with innodb_fast_shutdown = 0
2022-11-23 16:32:46 0x7fd6c57fa700  InnoDB: Assertion failure in thread 140560413206272 in file pars0pars.cc line 830
InnoDB: Failing assertion: sym_node->table != NULL
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.
16:32:46 UTC - xtrabackup got signal 6 ;

It seems both errors are the same but different from the one if I backup the demouk database. I also have tried to dump the xbackup database, not only the table and prep and export worked without issues

innobackupex --databases="xbackup" ./test
innobackupex --apply-log --export test/2022-11-23_16-37-06/

produced the following output

...
...
InnoDB: Creating shared tablespace for temporary tables
InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
InnoDB: File './ibtmp1' size is now 12 MB.
InnoDB: 96 redo rollback segment(s) found. 1 redo rollback segment(s) are active.
InnoDB: 32 non-redo rollback segment(s) are active.
InnoDB: 5.7.35 started; log sequence number 253911297551
InnoDB: page_cleaner: 1000ms intended loop took 17159ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)
xtrabackup: export option is specified.
xtrabackup: export metadata of table 'xbackup/FTS_000000000000a423_DELETED' to file `./xbackup/FTS_000000000000a423_DELETED.exp` (1 indexes)
xtrabackup:     name=FTS_COMMON_TABLE_IND, id.low=102540, page=3
xtrabackup: export metadata of table 'xbackup/FTS_000000000000a423_0000000000019095_INDEX_5' to file `./xbackup/FTS_000000000000a423_0000000000019095_INDEX_5.exp` (1 indexes)
xtrabackup:     name=FTS_INDEX_TABLE_IND, id.low=102554, page=3
xtrabackup: export metadata of table 'xbackup/FTS_000000000000a423_0000000000019095_INDEX_2' to file `./xbackup/FTS_000000000000a423_0000000000019095_INDEX_2.exp` (1 indexes)
xtrabackup:     name=FTS_INDEX_TABLE_IND, id.low=102551, page=3
xtrabackup: export metadata of table 'xbackup/FTS_000000000000a423_0000000000019095_INDEX_1' to file `./xbackup/FTS_000000000000a423_0000000000019095_INDEX_1.exp` (1 indexes)
xtrabackup:     name=FTS_INDEX_TABLE_IND, id.low=102550, page=3
xtrabackup: export metadata of table 'xbackup/FTS_000000000000a423_0000000000019095_INDEX_3' to file `./xbackup/FTS_000000000000a423_0000000000019095_INDEX_3.exp` (1 indexes)
xtrabackup:     name=FTS_INDEX_TABLE_IND, id.low=102552, page=3
xtrabackup: export metadata of table 'xbackup/checklists' to file `./xbackup/checklists.exp` (1 indexes)
xtrabackup:     name=PRIMARY, id.low=102533, page=3
xtrabackup: export metadata of table 'xbackup/taxcodes' to file `./xbackup/taxcodes.exp` (2 indexes)
xtrabackup:     name=PRIMARY, id.low=102534, page=3
xtrabackup:     name=taxcodes_code_dates_idx, id.low=102535, page=4
xtrabackup: export metadata of table 'xbackup/cataloguefolders' to file `./xbackup/cataloguefolders.exp` (2 indexes)
xtrabackup:     name=PRIMARY, id.low=102531, page=3
xtrabackup:     name=cataloguefolders_modified_idx, id.low=102532, page=4
xtrabackup: export metadata of table 'xbackup/FTS_000000000000a423_CONFIG' to file `./xbackup/FTS_000000000000a423_CONFIG.exp` (1 indexes)
xtrabackup:     name=FTS_COMMON_TABLE_IND, id.low=102539, page=3
xtrabackup: export metadata of table 'xbackup/FTS_000000000000a423_0000000000019095_INDEX_4' to file `./xbackup/FTS_000000000000a423_0000000000019095_INDEX_4.exp` (1 indexes)
xtrabackup:     name=FTS_INDEX_TABLE_IND, id.low=102553, page=3
xtrabackup: export metadata of table 'xbackup/FTS_000000000000a423_BEING_DELETED' to file `./xbackup/FTS_000000000000a423_BEING_DELETED.exp` (1 indexes)
xtrabackup:     name=FTS_COMMON_TABLE_IND, id.low=102537, page=3
xtrabackup: export metadata of table 'xbackup/catalogueitems' to file `./xbackup/catalogueitems.exp` (9 indexes)
xtrabackup:     name=PRIMARY, id.low=102536, page=3
xtrabackup:     name=FTS_DOC_ID_INDEX, id.low=102542, page=4
xtrabackup:     name=catalogue_object_idx, id.low=102543, page=5
xtrabackup:     name=catalogue_search_idx, id.low=102544, page=6
xtrabackup:     name=catalogues_modified_idx, id.low=102545, page=8
xtrabackup:     name=catalogueitems_checklist_fk, id.low=102546, page=9
xtrabackup:     name=catalogueitems_tax_code_fk, id.low=102547, page=10
xtrabackup:     name=catalogueitems_matgroup_idx, id.low=102548, page=12
xtrabackup:     name=catalogueitems_text, id.low=102549, page=4294967295
xtrabackup: export metadata of table 'xbackup/FTS_000000000000a423_0000000000019095_INDEX_6' to file `./xbackup/FTS_000000000000a423_0000000000019095_INDEX_6.exp` (1 indexes)
xtrabackup:     name=FTS_INDEX_TABLE_IND, id.low=102555, page=3
xtrabackup: export metadata of table 'xbackup/FTS_000000000000a423_DELETED_CACHE' to file `./xbackup/FTS_000000000000a423_DELETED_CACHE.exp` (1 indexes)
xtrabackup:     name=FTS_COMMON_TABLE_IND, id.low=102541, page=3
xtrabackup: export metadata of table 'xbackup/FTS_000000000000a423_BEING_DELETED_CACHE' to file `./xbackup/FTS_000000000000a423_BEING_DELETED_CACHE.exp` (1 indexes)
xtrabackup:     name=FTS_COMMON_TABLE_IND, id.low=102538, page=3
InnoDB: xtrabackup: Last MySQL binlog file position 90953245, file name db04-bin.000738

xtrabackup: starting shutdown with innodb_fast_shutdown = 0
InnoDB: FTS optimize thread exiting.
InnoDB: Starting shutdown...
InnoDB: Shutdown completed; log sequence number 253947666872
InnoDB: Number of pools: 1
xtrabackup: using the following InnoDB configuration for recovery:
xtrabackup:   innodb_data_home_dir = .
xtrabackup:   innodb_data_file_path = ibdata1:12M:autoextend
xtrabackup:   innodb_log_group_home_dir = .
xtrabackup:   innodb_log_files_in_group = 2
xtrabackup:   innodb_log_file_size = 268435456
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.7
InnoDB: Number of pools: 1
InnoDB: Using CPU crc32 instructions
InnoDB: Initializing buffer pool, total size = 100M, instances = 1, chunk size = 100M
InnoDB: Completed initialization of buffer pool
InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
InnoDB: Setting log file ./ib_logfile101 size to 256 MB
InnoDB: Progress in MB:
 100 200
InnoDB: Setting log file ./ib_logfile1 size to 256 MB
InnoDB: Progress in MB:
 100 200
InnoDB: Renaming log file ./ib_logfile101 to ./ib_logfile0
InnoDB: New log files created, LSN=253947666872
InnoDB: Highest supported file format is Barracuda.
InnoDB: Log scan progressed past the checkpoint lsn 253947666956
InnoDB: Doing recovery: scanned up to log sequence number 253947666965 (0%)
InnoDB: Database was not shutdown normally!
InnoDB: Starting crash recovery.
InnoDB: xtrabackup: Last MySQL binlog file position 90953245, file name db04-bin.000738
InnoDB: Removed temporary tablespace data file: "ibtmp1"
InnoDB: Creating shared tablespace for temporary tables
InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
InnoDB: File './ibtmp1' size is now 12 MB.
InnoDB: 96 redo rollback segment(s) found. 1 redo rollback segment(s) are active.
InnoDB: 32 non-redo rollback segment(s) are active.
InnoDB: 5.7.35 started; log sequence number 253947666965
xtrabackup: starting shutdown with innodb_fast_shutdown = 0
InnoDB: FTS optimize thread exiting.
InnoDB: Starting shutdown...
InnoDB: Shutdown completed; log sequence number 253947666984
221123 16:37:50 completed OK!

So now it looks even more confusing for me.

P.S. Thanks to you I now know how to link the index file to its table .

matthewb · November 23, 2022, 4:50pm

@tdc, asking for context, why do you need --export? Are you planning on importing tables one at a time? Also, be aware that innobackupex isn’t something you should be using (it’s technically dead/deprecated). You should be doing everything with xtrabackup. I believe innobackupex is actually just a command-line alias to xtrabackup now.

xtrabackup --prepare --export test/2022-11-22_22-08-31/

tdc · November 23, 2022, 10:02pm

@Marcelo_Altmann thank you for your comment, now I know how to figure out what table is the problem in :).
My previous comment has been flagged as spam and still is not available. However if I create a new database and create the table (with all related tables) there is no problem backup with the commands I’m using. So defo it’s a problem with the index itself. Tomorrow I will optimise the database, so it will recreate the indexes.

P.S. If my previous comment shows up, I know the answer of my question there, why the error is different - because I have backed up only this table without the related ones.

tdc · November 24, 2022, 10:27pm

@matthewb I need --export because I’m exporting single database demouk in this scenario and I need to import only it. In the docs it’s written Do not copy back the prepared backup. Restoring partial backups should be done by importing the tables, not by using the --copy-back option., so my understanding is that I need the --export argument.

By the way without the --export parameter and only with --prepare there is no error and I have tried to restore the database like this. I have managed to but have no idea what will happen when I start using it. Additionally it took a very long time to do so 2h for 9GB of backup and this will be because the mysql log is full of [Warning] [MY-012378] [InnoDB] Reading max(auto_inc_col) = 2798 for table local_demouk.{TABLE_NAME}, because there was an IMPORT without cfg file.

matthewb · November 25, 2022, 4:15pm

You need the --export argument because without it, xtrabackup will not produce the .cfg file which is required for the import process.

Topic		Replies	Views
Using innobackupex-1.5.1 failing with this report. Percona XtraBackup	1	734	September 18, 2013
Export/Import Individual Tables? Percona XtraBackup	1	559	June 24, 2013
innobackupex/xtrabackup fails at --apply-log phase Percona XtraBackup	1	1411	September 25, 2014
Xtrabackup --prepare crashes, please help get a valid backup (solved) Percona XtraBackup	7	2418	November 3, 2022
Xtrabackup failing on 5.6 Percona XtraBackup	0	492	September 24, 2014

I am unable to `innobackupex --apply-log --export` for any backup I made

Related topics