Xtrabackup losing files

MySQL & MariaDB Percona XtraBackup
1

Just saying.

xtrabackup --backup […]
[OK!]
xtrabackup --prepare […]
[OK!]
xtrabackup --move-back […]
[OK!]

And then starting mysqld says it’s missing some innodb files. You count the ibd/frm files inside the master and replica - and yeah, the replica count is way less. Has someone seen something similar or it’s just me ? 8.0.26. I personally have seen this three times already. It’s not that reproducible - I mean, second time in a row the backup is usually okay. But the whole picture is quite disturbing. Well, when the utility says “okay” you think that it is okay, usually there’s no need to overcheck. Not in the case with xtrabackup though…

1 Like
2

Could you explain more on what the exact error message is?

1 Like
3

Sure, here’s the log of last failed move-back: mysql server is cleanstarting the newly created datadir:

2022-03-18T16:57:40.6NZ mysqld_safe Logging to '/var/db/mysql/db1-de.findmykids.org.err'.
2022-03-18T16:57:40.6NZ mysqld_safe Starting mysqld daemon with databases from /var/db/mysql
mysqld: Error on delete of '/var/db/mysql/auto.cnf' (OS errno 2 - No such file or directory)
2022-03-18T16:57:40.514113Z 0 [Warning] [MY-010918] [Server] 'default_authentication_plugin' is deprecated and will be removed in a future release. Please use authentication_policy instead.
2022-03-18T16:57:40.514131Z 0 [System] [MY-010116] [Server] /usr/local/libexec/mysqld (mysqld 8.0.28) starting as process 29091
2022-03-18T16:57:40.526118Z 0 [Warning] [MY-010107] [Server] World-writable config file '/var/db/mysql/auto.cnf' has been removed.
2022-03-18T16:57:40.527780Z 0 [Warning] [MY-010075] [Server] No existing UUID has been found, so we assume that this is the first time that this server has been started. Generating a new UUID: 858d203c-a6dc-11ec-bef7-e0d55ec6fe2c.
2022-03-18T16:57:40.532836Z 1 [System] [MY-013576] [InnoDB] InnoDB initialization has started.
2022-03-18T16:58:01.678776Z 1 [System] [MY-013577] [InnoDB] InnoDB initialization has ended.
2022-03-18T16:58:01.875732Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 8382, name 'wimc_from_binlogs/mp_appCategory', file './wimc_from_binlogs/mp_appCategory.ibd' is missing!
2022-03-18T16:58:01.875968Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 8390, name 'wimc_from_binlogs/mp_appNotificationLaunchCategory', file './wimc_from_binlogs/mp_appNotificationLaunchCategory.ibd' is missing!
2022-03-18T16:58:01.876995Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 8436, name 'wimc_from_binlogs/mp_promoCode', file './wimc_from_binlogs/mp_promoCode.ibd' is missing!
2022-03-18T16:58:01.877628Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 8458, name 'wimc_from_binlogs/mp_subscription', file './wimc_from_binlogs/mp_subscription.ibd' is missing!
2022-03-18T16:58:01.877738Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 8462, name 'wimc_from_binlogs/mp_testResult', file './wimc_from_binlogs/mp_testResult.ibd' is missing!
2022-03-18T16:58:01.877951Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 8469, name 'wimc_from_binlogs/mp_userPhoneCall', file './wimc_from_binlogs/mp_userPhoneCall.ibd' is missing!
2022-03-18T16:58:01.878204Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 8480, name 'wimc_from_binlogs/tmp_23and8marchuser', file './wimc_from_binlogs/tmp_23and8marchuser.ibd' is missing!
2022-03-18T16:58:01.882362Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27108, name 'wimc_bitrix_watch/b_user_password', file './wimc_bitrix_watch/b_user_password.ibd' is missing!
2022-03-18T16:58:01.882559Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27113, name 'wimc_bitrix_watch/fts_0000000000019a62_deleted', file './wimc_bitrix_watch/fts_0000000000019a62_deleted.ibd' is missing!
2022-03-18T16:58:01.882952Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27128, name 'wimc_bitrix_watch/fts_0000000000019a62_00000000000238d9_index_2', file './wimc_bitrix_watch/fts_0000000000019a62_00000000000238d9_index_2.ibd' is missing!
2022-03-18T16:58:01.883711Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27159, name 'wimc_bitrix_watch/b_site_template', file './wimc_bitrix_watch/b_site_template.ibd' is missing!
2022-03-18T16:58:01.883982Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27168, name 'wimc_bitrix_watch/b_group_task', file './wimc_bitrix_watch/b_group_task.ibd' is missing!
2022-03-18T16:58:01.884369Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27184, name 'wimc_bitrix_watch/b_rating_vote_group', file './wimc_bitrix_watch/b_rating_vote_group.ibd' is missing!
2022-03-18T16:58:01.884465Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27186, name 'wimc_bitrix_watch/b_event_log', file './wimc_bitrix_watch/b_event_log.ibd' is missing!
2022-03-18T16:58:01.884686Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27195, name 'wimc_bitrix_watch/b_user_access', file './wimc_bitrix_watch/b_user_access.ibd' is missing!
2022-03-18T16:58:01.885017Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27209, name 'wimc_bitrix_watch/b_finder_dest', file './wimc_bitrix_watch/b_finder_dest.ibd' is missing!
2022-03-18T16:58:01.885410Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27223, name 'wimc_bitrix_watch/b_numerator', file './wimc_bitrix_watch/b_numerator.ibd' is missing!
2022-03-18T16:58:01.885492Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27226, name 'wimc_bitrix_watch/b_user_profile_record', file './wimc_bitrix_watch/b_user_profile_record.ibd' is missing!
2022-03-18T16:58:01.885690Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27234, name 'wimc_bitrix_watch/b_b24connector_buttons', file './wimc_bitrix_watch/b_b24connector_buttons.ibd' is missing!
2022-03-18T16:58:01.886111Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27249, name 'wimc_bitrix_watch/b_blog_post_category', file './wimc_bitrix_watch/b_blog_post_category.ibd' is missing!
2022-03-18T16:58:01.886310Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27257, name 'wimc_bitrix_watch/b_catalog_iblock', file './wimc_bitrix_watch/b_catalog_iblock.ibd' is missing!
2022-03-18T16:58:01.887124Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27292, name 'wimc_bitrix_watch/b_catalog_subscribe', file './wimc_bitrix_watch/b_catalog_subscribe.ibd' is missing!
2022-03-18T16:58:01.887452Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27303, name 'wimc_bitrix_watch/b_conv_context_attribute', file './wimc_bitrix_watch/b_conv_context_attribute.ibd' is missing!
2022-03-18T16:58:01.887762Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27316, name 'wimc_bitrix_watch/b_sticker_group_task', file './wimc_bitrix_watch/b_sticker_group_task.ibd' is missing!
2022-03-18T16:58:01.888164Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27333, name 'wimc_bitrix_watch/b_form_crm_field', file './wimc_bitrix_watch/b_form_crm_field.ibd' is missing!
2022-03-18T16:58:01.888447Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27342, name 'wimc_bitrix_watch/b_forum_rank_lang', file './wimc_bitrix_watch/b_forum_rank_lang.ibd' is missing!
2022-03-18T16:58:01.888556Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27346, name 'wimc_bitrix_watch/b_forum_points_lang', file './wimc_bitrix_watch/b_forum_points_lang.ibd' is missing!
2022-03-18T16:58:01.888626Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27347, name 'wimc_bitrix_watch/b_forum_points2post', file './wimc_bitrix_watch/b_forum_points2post.ibd' is missing!
2022-03-18T16:58:01.888867Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27357, name 'wimc_bitrix_watch/b_forum_stat', file './wimc_bitrix_watch/b_forum_stat.ibd' is missing!
2022-03-18T16:58:01.889018Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27363, name 'wimc_bitrix_watch/b_hlblock_entity_rights', file './wimc_bitrix_watch/b_hlblock_entity_rights.ibd' is missing!
2022-03-18T16:58:01.889627Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27387, name 'wimc_bitrix_watch/b_iblock_iproperty', file './wimc_bitrix_watch/b_iblock_iproperty.ibd' is missing!
2022-03-18T16:58:01.889795Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27396, name 'wimc_bitrix_watch/b_landing_template_ref', file './wimc_bitrix_watch/b_landing_template_ref.ibd' is missing!
2022-03-18T16:58:01.890178Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27412, name 'wimc_bitrix_watch/b_landing_chat_binding', file './wimc_bitrix_watch/b_landing_chat_binding.ibd' is missing!
2022-03-18T16:58:01.890348Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27422, name 'wimc_bitrix_watch/fts_0000000000019b93_being_deleted_cache', file './wimc_bitrix_watch/fts_0000000000019b93_being_deleted_cache.ibd' is missing!
2022-03-18T16:58:01.890864Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27432, name 'wimc_bitrix_watch/fts_0000000000019b9f_0000000000023b87_index_6', file './wimc_bitrix_watch/fts_0000000000019b9f_0000000000023b87_index_6.ibd' is missing!
2022-03-18T16:58:01.891499Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27462, name 'wimc_bitrix_watch/b_pull_watch', file './wimc_bitrix_watch/b_pull_watch.ibd' is missing!
2022-03-18T16:58:01.891529Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27463, name 'wimc_bitrix_watch/b_report', file './wimc_bitrix_watch/b_report.ibd' is missing!
2022-03-18T16:58:01.891863Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27477, name 'wimc_bitrix_watch/b_rest_log', file './wimc_bitrix_watch/b_rest_log.ibd' is missing!
2022-03-18T16:58:01.892214Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27489, name 'wimc_bitrix_watch/b_sale_lang', file './wimc_bitrix_watch/b_sale_lang.ibd' is missing!
2022-03-18T16:58:01.892294Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27492, name 'wimc_bitrix_watch/b_sale_basket_props', file './wimc_bitrix_watch/b_sale_basket_props.ibd' is missing!
2022-03-18T16:58:01.892352Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27495, name 'wimc_bitrix_watch/b_sale_order_props_group', file './wimc_bitrix_watch/b_sale_order_props_group.ibd' is missing!
2022-03-18T16:58:01.892485Z 1 [Warning] [MY-012351] [InnoDB] Tablespace 27498, name 'wimc_bitrix_watch/b_sale_order_props_variant', file './wimc_bitrix_watch/b_sale_order_props_variant.ibd' is missing!

Both backup/prepare runs finished with “OK” message. Move-back run did this also. No, I did not save the log sequences for these (guilty). Will start saving next time I will try to reinit this replica (actually I’m doing it right now). And yes, I’m aware that move-back run, whether stopped or finished, does corrupt the backup (another disturbing issue), so I’m preserving it with a zfs snapshot; in case if I interrupt the move-back run I just rollback the target-dir to the snapshot state. However, this was not the case - I did not restart the move-back. I started it once, it finished with success.

1 Like
4

If you use --copy-back instead of move, then your backup will still be there. When you do this again, is it the same tables/files that are missing, or is it different tables each time?

1 Like
5

Different tables/databases are missing each backup-prepare-move-back iterations, not sure if they differ on each --move-back using the same prepared set of files, I suppose they are the same . Last time I took the copy of --move-back with script utility. After --move back said “OK” 4 files are again missing, I took the “ls -1” in the original instance directory tree and in restored one and then took a diff between two listings:

--- /tmp/wimc.txt.orig  2022-03-25 11:14:31.705051000 +0300
+++ /tmp/wimc.txt       2022-03-25 11:15:07.640460000 +0300
@@ -1,4 +1,3 @@
-__mp_userDevice_new.ibd
_mp_userDevice_new.ibd
e0.ibd
e1.ibd
@@ -94,7 +93,6 @@
mp_deviceUser.ibd
mp_dispatch.ibd
mp_dispatchEmailUnsubscribe.ibd
-mp_dispatchNew.ibd
mp_dispatchPool.ibd
mp_dispatchPoolUser.ibd
mp_dispatchPushCard.ibd
@@ -158,7 +156,6 @@
mp_nyUserGift_2021.ibd
mp_nyUserGift.ibd
mp_oauthToken.ibd
-mp_oauthUser.ibd
mp_order_cdek.ibd
mp_order.ibd
mp_orderDeliveryStatus.ibd
@@ -192,7 +189,6 @@
mp_queryLog#p#p_august.ibd
mp_queryLog#p#p_december.ibd
mp_queryLog#p#p_july.ibd
-mp_queryLog#p#p_june.ibd
mp_queryLog#p#p_last.ibd
mp_queryLog#p#p_march.ibd
mp_queryLog#p#p_may.ibd

So, one of the files is mp_dispatchNew.ibd. First question is - is this file present in the backup ? Let’s zfs rollback the backup dir to a pristine snapshot taken immediately after the prepare finised it’s work:


[root@balancer1-de:db0-de/wimc]# zfs rollback data/public/backups@pristine
[root@balancer1-de:db0-de/wimc]# zfs get mountpoint data/public/backups
NAME                 PROPERTY    VALUE                      SOURCE
data/public/backups  mountpoint  /usr/local/public/backups  inherited from data/public
[root@balancer1-de:db0-de/wimc]# ls -l /usr/local/public/backups/db0-de/wimc/mp_dispatchNew.ibd
-rw-r-----  1 root  wheel  131072 23 марта 07:22 /usr/local/public/backups/db0-de/wimc/mp_dispatchNew.ibd

Let’s take a look in the restore log and see whether it mention this table at all:

[root@db1-de:~]# grep mp_dispatchNew.ibd /home/emz/restore.log
[root@db1-de:~]# wc -l /home/emz/restore.log
9774 /home/emz/restore.log

So, the xtrabackup merely doesn’t mention it, though restore.log is definitely not empty. Unfortunately, I don’t have the backup/prepare log, may be the clue lies there. Will retake the backup with full logging this time.

1 Like