一次使用innobackupex重新搭建主從複製報錯解決方法及注意事項
【環境介紹】
系統環境：CentOS release 6.4 (Final) + Server version: 5.7.18-log MySQL Community Server (GPL) + innobackupex version 2.4.12 Linux (x86_64)
【背景描述】
使用innobackupex重新全備搭建主從複製步驟簡單，但是由於歷史原因在全備恢復後出現報錯：。
[ERROR] InnoDB: Unable to open undo tablespace './/undo001'.
[ERROR] InnoDB: Plugin initialization aborted with error Generic error
[ERROR] Plugin 'InnoDB' init function returned error.
[ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
【實施步驟】
主庫操作：
主庫備份全庫
innobackupex --defaults-file=/etc/my.cnf --user=root --password=mysql -S /tmp/mysql.sock /root/backup
[[email protected] backup]# innobackupex --defaults-file=/etc/my.cnf --user=root --password=mysql -S /tmp/mysql.sock /root/backupxtrabackup: recognized server arguments: --datadir=/var/lib/mysql/data --server-id=101 --open_files_limit=65535 --tmpdir=/home/mysql/tmp --innodb_buffer_pool_size=1G --innodb_flush_log_at_trx_commit=1 --innodb_undo_tablespaces=3 - ......》》》省略輸出內容 xtrabackup: Transaction log of lsn (2458487) to (2458496) was copied.
181222 04:40:18 completed OK!
[
將備份檔案拷貝至備庫
[[email protected] backup]# tar -cvf 2018-12-22_04-39-56.tar 2018-12-22_04-39-56/2018-12-22_04-39-56/
....》》省略部分
2018-12-22_04-39-56/sys/[email protected]_summary_by_statement_type.frm
[[email protected] backup]# [[email protected]
[email protected]'s password:
2018-12-22_04-39-56.tar 100% 299MB 37.4MB/s 00:08
[[email protected] backup]#
備庫操作：
關閉資料庫
[[email protected] mysql]# mysqladmin --defaults-file=/etc/my.cnf --protocol=tcp -P3306 shutdown -uroot -pmysql
[[email protected] mysql]#
[1]+ Done mysqld --defaults-file=/etc/my.cnf --user=mysql (wd: ~)
(wd now: /var/lib/mysql)
[[email protected] mysql]#
備份原庫資料
[[email protected] mysql]# ls -trl
total 56
drwxr-xr-x. 6 mysql mysql 4096 Dec 22 08:47 data
[[email protected] mysql]# mv data data_bak
進行全庫恢復
進行--apply-log操作
[[email protected] mysql]# innobackupex --defaults-file=/etc/my.cnf --apply-log /root/backup/2018-12-22_04-39-56xtrabackup: recognized server arguments: --innodb_checksum_algorithm=crc32 --innodb_log_checksum_algorithm=strict_crc32 --innodb_data_file_path=ibdata1:256M:autoextend --innodb_log_files_in_group=2 -- ....》》省略部分 InnoDB: Shutdown completed; log sequence number 2459176
181222 08:52:03 completed OK!
[[email protected] mysql]#
進行--copy-back操作
[[email protected] mysql]# innobackupex --defaults-file=/etc/my.cnf --copy-back /root/backup/2018-12-22_04-39-56
xtrabackup: recognized server arguments: --datadir=/var/lib/mysql/data --server-id=100 --open_files_limit=65535 --tmpdir=/home/mysql/tmp --innodb_buffer_pool_size=1G --innodb_flush_log_at_trx_commit=1 --innodb_log_buffer_size=32M -
....》》省略部分
181222 08:53:24 [01] ...done
181222 08:53:24 completed OK!
[[email protected] mysql]#
修改資料檔案目錄許可權
[[email protected] mysql]# chown -R mysql:mysql data
直接啟動資料庫
[[email protected] mysql]#mysqld --defaults-file=/etc/my.cnf --user=mysql &
檢視日誌出現報錯：
2018-12-22T13:56:08.963837Z 0 [Warning] option 'table_definition_cache': unsigned value 64 adjusted to 4002018-12-22T13:56:09.138266Z 0 [Warning] option 'max_binlog_size': unsigned value 2147483648 adjusted to 1073741824
2018-12-22T13:56:09.138392Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2018-12-22T13:56:09.138450Z 0 [Warning] Insecure configuration for --secure-file-priv: Current value does not restrict location of generated files. Consider setting it to a valid, non-empty path.
2018-12-22T13:56:09.138502Z 0 [Note] mysqld (mysqld 5.7.18-log) starting as process 4873 ...
2018-12-22T13:56:09.197459Z 0 [Note] InnoDB: PUNCH HOLE support not available
2018-12-22T13:56:09.197501Z 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2018-12-22T13:56:09.197513Z 0 [Note] InnoDB: Uses event mutexes
2018-12-22T13:56:09.197525Z 0 [Note] InnoDB: GCC builtin __sync_synchronize() is used for memory barrier
2018-12-22T13:56:09.197536Z 0 [Note] InnoDB: Compressed tables use zlib 1.2.3
2018-12-22T13:56:09.197547Z 0 [Note] InnoDB: Using Linux native AIO
2018-12-22T13:56:09.198473Z 0 [Note] InnoDB: Number of pools: 1
2018-12-22T13:56:09.198675Z 0 [Note] InnoDB: Using CPU crc32 instructions
2018-12-22T13:56:09.200901Z 0 [Note] InnoDB: Initializing buffer pool, total size = 1G, instances = 1, chunk size = 128M
2018-12-22T13:56:09.400867Z 0 [Note] InnoDB: Completed initialization of buffer pool
2018-12-22T13:56:09.408553Z 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2018-12-22T13:56:09.494523Z 0 [ERROR] InnoDB: Unable to open undo tablespace './/undo001'.
2018-12-22T13:56:09.494551Z 0 [ERROR] InnoDB: Plugin initialization aborted with error Generic error
2018-12-22T13:56:10.101405Z 0 [ERROR] Plugin 'InnoDB' init function returned error.
2018-12-22T13:56:10.101433Z 0 [ERROR] Plugin 'InnoDB' registration as a STORAGE ENGINE failed.
2018-12-22T13:56:10.101443Z 0 [ERROR] Failed to initialize plugins.
2018-12-22T13:56:10.101451Z 0 [ERROR] Aborting 2018-12-22T13:56:10.101465Z 0 [Note] Binlog end
2018-12-22T13:56:10.101521Z 0 [Note] Shutting down plugin 'CSV'
2018-12-22T13:56:10.102134Z 0 [Note] mysqld: Shutdown complete
【問題解決】
從以上報錯發現無法開啟undo tablespace undo001，檢視備庫資料目錄檢視，確實不存在undo001，檢視主庫存在undo001表空間。
從恢復日誌看--apply-log的時候石有undo表空間的資訊
InnoDB: Opened 3 undo tablespaces
InnoDB: 3 undo tablespaces made active
從恢復日誌看--copy-back的時候並沒有拷貝undo表空間的資訊。思考為啥沒有copy的undo表空間到資料目錄資訊
innobackupex --defaults-file=/etc/my.cnf --apply-log /root/backup/2018-12-22_04-39-56
根據思路從命令恢復的可以看出涉及兩個檔案確認undo表空間資訊/etc/my.cnf，/root/backup/2018-12-22_04-39-56
[[email protected] ~]# cat /etc/my.cnf |grep undo
[[email protected] ~]# ls -trl /root/backup/2018-12-22_04-39-56|grep undo
-rw-r-----. 1 root root 10485760 Dec 22 08:51 undo003
-rw-r-----. 1 root root 10485760 Dec 22 08:51 undo002
-rw-r-----. 1 root root 10485760 Dec 22 08:51 undo001
[[email protected] ~]#
從上面的結果可以看出備份檔案中是存在undo表空間且是3個undo表空間，但是從引數檔案中不存在undo表空間的資訊
至此可以初步斷定為引數檔案中沒有指定undo表空間資訊，於是在配置檔案中新增innodb_undo_tablespaces=3，再次--apply-log操作
觀察日誌資訊，已經存在undo拷貝操作
innobackupex version 2.4.12 based on MySQL server 5.7.19 Linux (x86_64) (revision id: 170eb8c)
181223 03:09:12 [01] Copying undo001 to /var/lib/mysql/data/undo001
181223 03:09:12 [01] ...done
181223 03:09:12 [01] Copying undo002 to /var/lib/mysql/data/undo002
181223 03:09:13 [01] ...done
181223 03:09:13 [01] Copying undo003 to /var/lib/mysql/data/undo003
181223 03:09:13 [01] ...done
181223 03:09:14 [01] Copying ib_logfile0 to /var/lib/mysql/data/ib_logfile0
181223 03:09:15 [01] ...done
181223 03:09:15 [01] Copying ib_logfile1 to /var/lib/mysql/data/ib_logfile1
於是手工再次啟動資料庫，資料庫正常拉起，沒有undo報錯，繼續搭建主從複製。
【錯誤日誌warring】
2018-12-22T13:56:08.963837Z 0 [Warning] option 'table_definition_cache': unsigned value 64 adjusted to 400
2018-12-22T13:56:09.138266Z 0 [Warning] option 'max_binlog_size': unsigned value 2147483648 adjusted to 1073741824
2018-12-22T13:56:09.138392Z 0 [Warning] TIMESTAMP with implicit DEFAULT value is deprecated. Please use --explicit_defaults_for_timestamp server option (see documentation for more details).
2018-12-22T13:56:09.138450Z 0 [Warning] Insecure configuration for --secure-file-priv: Current value does not restrict location of generated files. Consider setting it to a valid, non-empty path.
根據5.7官方文件對應引數調整如下：
table_definition_cache預設值為400，可以調整400 + (table_open_cache / 2)
max_binlog_size=1024M
explicit_defaults_for_timestamp = ON
secure_file_priv = " "
【主從複製搭建】
[[email protected] 2018-12-22_04-39-56]# cat xtrabackup_binlog_info
binlog.000011 489 2478c036-bd7a-11e8-85df-080027206a62:5-6,fbfd9bcb-0437-11e9-947d-080027206a62:1-9
[[email protected] 2018-12-22_04-39-56]#
mysql> reset master;
Query OK, 0 rows affected (0.12 sec) mysql> set global gtid_purged='2478c036-bd7a-11e8-85df-080027206a62:5-6,fbfd9bcb-0437-11e9-947d-080027206a62:1-9';
Query OK, 0 rows affected (0.00 sec) mysql> change master to master_user= 'repl',master_host='192.168.8.101',master_password='repl',master_port=3306,MASTER_AUTO_POSITION=1;
Query OK, 0 rows affected, 2 warnings (0.48 sec) mysql> start slave;
Query OK, 0 rows affected (0.04 sec) mysql> show slave status\G
*************************** 1. row ***************************
Slave_IO_State: Waiting for master to send event
Master_Host: 192.168.8.101
Master_User: repl
Master_Port: 3306
Connect_Retry: 60
Master_Log_File: binlog.000013
Read_Master_Log_Pos: 234
Relay_Log_File: mysqldb1-relay-bin.000002
Relay_Log_Pos: 361
Relay_Master_Log_File: binlog.000013
Slave_IO_Running: Yes
Slave_SQL_Running: Yes ........省略部分輸出內容 Executed_Gtid_Set: 2478c036-bd7a-11e8-85df-080027206a62:5-6,fbfd9bcb-0437-11e9-947d-080027206a62:1-9
Auto_Position: 1
Replicate_Rewrite_DB:
Channel_Name:
Master_TLS_Version:
1 row in set (0.00 sec) mysql> 測試資料同步正常
【總結】
innobackupex備份恢復前確認主庫跟恢復庫的引數一致，可以使用diff命令檢視引數的必要性；
可能由於歷史原因引數沒有寫到配置檔案報錯，應該做好工程修改記錄對於問題查詢有很大的作用。