2023-06-21T10:29:36.685670+08:00 0 [Note] [MY-011825] [Xtrabackup] Connecting to MySQL server host: 127.0.0.1, user: root, password: set, port: 3380, socket: not set 2023-06-21T10:29:36.714220+08:00 0 [Note] [MY-011825] [Xtrabackup] Using server version 8.0.32
2023-06-21T10:29:36.719676+08:00 0 [Note] [MY-011825] [Xtrabackup] Executing LOCK INSTANCE FOR BACKUP ... 2023-06-21T10:29:36.721377+08:00 0 [Note] [MY-011825] [Xtrabackup] uses posix_fadvise(). 2023-06-21T10:29:36.721453+08:00 0 [Note] [MY-011825] [Xtrabackup] cd to /data/mysql8.0/data/ 2023-06-21T10:29:36.721478+08:00 0 [Note] [MY-011825] [Xtrabackup] open files limit requested 0, set to 65536
2023-06-21T10:29:37.086200+08:00 0 [Note] [MY-011825] [Xtrabackup] Starting to parse redo log at lsn = 22021170
2023-06-21T10:29:43.354808+08:00 0 [Note] [MY-011825] [Xtrabackup] Starting to backup non-InnoDB tables and files
2023-06-26T10:20:02.359130+08:00 0 [Note] [MY-013883] [InnoDB] The latest found checkpoint is at lsn = 27517178 in redo log file ./#innodb_redo/#ib_redo0. 2023-06-26T10:20:02.359262+08:00 0 [Note] [MY-012560] [InnoDB] The log sequence number 19019361 in the system tablespace does not match the log sequence number 27517178 in the redo log files! 2023-06-26T10:20:02.359283+08:00 0 [Note] [MY-012551] [InnoDB] Database was not shutdown normally! 2023-06-26T10:20:02.359296+08:00 0 [Note] [MY-012552] [InnoDB] Starting crash recovery. 2023-06-26T10:20:02.367962+08:00 0 [Note] [MY-013086] [InnoDB] Starting to parse redo log at lsn = 27516952, whereas checkpoint_lsn = 27517178 and start_lsn = 27516928 2023-06-26T10:20:02.418985+08:00 0 [Note] [MY-012550] [InnoDB] Doing recovery: scanned up to log sequence number 30394287
2023-06-26T10:20:05.103532+08:00 0 [Note] [MY-013084] [InnoDB] Log background threads are being closed... 2023-06-26T10:20:05.105082+08:00 0 [Note] [MY-013888] [InnoDB] Upgrading redo log: 1032M, LSN=30394340. 2023-06-26T10:20:05.105113+08:00 0 [Note] [MY-012968] [InnoDB] Starting to delete and rewrite redo log files. 2023-06-26T10:20:05.105284+08:00 0 [Note] [MY-011825] [InnoDB] Removing redo log file: ./#innodb_redo/#ib_redo0 2023-06-26T10:20:05.207953+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-06-26T10:20:05.218735+08:00 0 [Note] [MY-011825] [InnoDB] Renaming redo log file from ./#innodb_redo/#ib_redo0_tmp to ./#innodb_redo/#ib_redo0 2023-06-26T10:20:05.225168+08:00 0 [Note] [MY-012893] [InnoDB] New redo log files created, LSN=30394380
2023-06-26T10:20:07.118724+08:00 0 [Note] [MY-011825] [Xtrabackup] completed OK
xtrabackup prepare命令会启动一个临时的mysql实例,依赖innodb的恢复机制来应用redo文件。xtrabackup对恢复代码进行了一些改造,只应用序列号不大于last_lsn的redo日志,这一点可以从这一行日志中看出:“Doing recovery: scanned up to log sequence number 30394287”。
2023-06-26T03:21:35.299596Z mysqld_safe Logging to '/data/full_restore/log/alert.log'. 2023-06-26T03:21:35.340097Z mysqld_safe Starting mysqld daemon with databases from /data/full_restore/data
查看mysql的错误日志,检查实例是否启动成功。
1 2 3 4 5 6 7 8 9 10 11
[root@172-16-121-234 full]# tail /data/full_restore/log/alert.log 2023-06-26T03:21:38.109286Z 0 [System] [MY-010229] [Server] Starting XA crash recovery... 2023-06-26T03:21:38.152446Z 0 [System] [MY-010232] [Server] XA crash recovery finished. 2023-06-26T03:21:38.414645Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed. 2023-06-26T03:21:38.414702Z 0 [System] [MY-013602] [Server] Channel mysql_main configured to support TLS. Encrypted connections are now supported for this channel. 2023-06-26T03:21:38.491284Z 0 [ERROR] [MY-010544] [Repl] Failed to open the relay log '/data/mysql8.0/relaylog/relaylog.000006' (relay_log_pos 407). 2023-06-26T03:21:38.491320Z 0 [ERROR] [MY-011059] [Repl] Could not find target log file mentioned in relay log info in the index file '/data/full_restore/relaylog/relaylog.index' during relay log initialization. 2023-06-26T03:21:38.495637Z 0 [ERROR] [MY-010426] [Repl] Slave: Failed to initialize the master info structure for channel ''; its record may still be present in 'mysql.slave_master_info' table, consider deleting it. 2023-06-26T03:21:38.495677Z 0 [ERROR] [MY-010529] [Repl] Failed to create or recover replication info repositories. 2023-06-26T03:21:38.495730Z 0 [Warning] [MY-010530] [Repl] Detected misconfiguration: replication channel '' was configured with AUTO_POSITION = 1, but the server was started with --gtid-mode=off. Either reconfigure replication using CHANGE MASTER TO MASTER_AUTO_POSITION = 0 FOR CHANNEL '', or change GTID_MODE to some value other than OFF, before starting the slave receiver thread. 2023-06-26T03:21:38.499008Z 0 [System] [MY-010931] [Server] /opt/mysql/bin/mysqld: ready for connections. Version: '8.0.32' socket: '/data/full_restore/run/mysql.sock' port: 6380 MySQL Community Server - GPL.
# cat xtrabackup_slave_info SET GLOBAL gtid_purged='58224b02-09b7-11ee-90bd-fab81f64ee00:1-13191,7caa9a48-b325-11ed-8541-fab81f64ee00:1-27'; CHANGE MASTER TO MASTER_AUTO_POSITION=1;
2023-06-26T06:32:18.756919Z mysqld_safe Logging to '/data/full_restore/log/alert.log'. 2023-06-26T06:32:18.799475Z mysqld_safe Starting mysqld daemon with databases from /data/full_restore/data
查看启动日志,检查实例是否启动成功。
1 2 3 4 5 6 7 8
[root@172-16-121-234 full]# tail -10 /data/full_restore/log/alert.log ...... 2023-06-26T06:32:21.793703Z 0 [ERROR] [MY-010544] [Repl] Failed to open the relay log '/data/mysql8.0/relaylog/relaylog.000006' (relay_log_pos 407). 2023-06-26T06:32:21.793742Z 0 [ERROR] [MY-011059] [Repl] Could not find target log file mentioned in relay log info in the index file '/data/full_restore/relaylog/relaylog.index' during relay log initialization. 2023-06-26T06:32:21.797553Z 0 [ERROR] [MY-010426] [Repl] Slave: Failed to initialize the master info structure for channel ''; its record may still be present in 'mysql.slave_master_info' table, consider deleting it. 2023-06-26T06:32:21.797596Z 0 [ERROR] [MY-010529] [Repl] Failed to create or recover replication info repositories. 2023-06-26T06:32:21.797633Z 0 [Warning] [MY-010530] [Repl] Detected misconfiguration: replication channel '' was configured with AUTO_POSITION = 1, but the server was started with --gtid-mode=off. Either reconfigure replication using CHANGE MASTER TO MASTER_AUTO_POSITION = 0 FOR CHANNEL '', or change GTID_MODE to some value other than OFF, before starting the slave receiver thread. 2023-06-26T06:32:21.800913Z 0 [System] [MY-010931] [Server] /opt/mysql/bin/mysqld: ready for connections. Version: '8.0.32' socket: '/data/full_restore/run/mysql.sock' port: 6380 MySQL Community Server - GPL.
如果实例支持backup lock(如percona server),会使用lock tables for backup代替flush tables with read lock。
如果备份的数据库上有长时间运行的SQL或未提交的事务,无法获取到全局锁(flush tables with read lock),这种情况下,如果执行了flush tables with read lock命令,会导致整个实例无法写入,需要等长时间运行的SQL结束后才能恢复正常。为了避免出现这种情况,xtrabackup提供了几个选项,你可以根据需要进行选择。