记一次使用innobackupex做全备恢复失败的经历
时间:2018-12-18 17:59 来源:linux.it.net.cn 作者:IT
记一次使用innobackupex做全备恢复失败的经历
在分别使用innobackupex --apply-log和innobackupex --copy-back命令成功后，相关信息如下：
[root@node3 app]#innobackupex --apply-log /app/backup/2018-05-07_22-49-42/
180507 22:57:49 innobackupex: Starting the apply-log operation
IMPORTANT: Please check that the apply-log run completes successfully.
At the end of a successful apply-log run innobackupex
prints "completed OK!".
innobackupex version 2.4.9 based on MySQL server 5.7.13 Linux (x86_64) (revision id: a467167cdd4)
xtrabackup: cd to /app/backup/2018-05-07_22-49-42/
xtrabackup: This target seems to be not prepared yet.
InnoDB: Number of pools: 1
xtrabackup: xtrabackup_logfile detected: size=8388608, start_lsn=(6986796)
xtrabackup: using the following InnoDB configuration for recovery:
…… ……
InnoDB: 5.7.13 started; log sequence number 6987285
xtrabackup: starting shutdown with innodb_fast_shutdown = 1
InnoDB: FTS optimize thread exiting.
InnoDB: Starting shutdown...
InnoDB: Shutdown completed; log sequence number 6987304
180507 22:57:54 completed OK!
[root@node3 app]#innobackupex --copy-back /app/backup/2018-05-07_22-49-42/
180507 22:58:36 innobackupex: Starting the copy-back operation
IMPORTANT: Please check that the copy-back run completes successfully.
At the end of a successful copy-back run innobackupex
prints "completed OK!".
innobackupex version 2.4.9 based on MySQL server 5.7.13 Linux (x86_64) (revision id: a467167cdd4)
180507 22:58:36 [01] Copying ib_logfile0 to /var/lib/mysql/ib_logfile0
180507 22:58:36 [01] ...done
…… ……
180507 22:58:38 [01] Copying ./xtrabackup_info to /var/lib/mysql/xtrabackup_info
180507 22:58:38 [01] ...done
180507 22:58:38 [01] Copying ./ibtmp1 to /var/lib/mysql/ibtmp1
180507 22:58:38 [01] ...done
180507 22:58:38 completed OK!
数据恢复按理说是成功了，于是我就直接启动mysqld服务，但是：
[root@node3 app]#systemctl restart mysql
Job for mariadb.service failed because the control process exited with error code. See "systemctl status mariadb.service" and "journalctl -xe" for details.
服务启动失败！同时有很多诸如以下的报错信息：
May 07 23:04:42 node3.test.com mysqld[1501]: 2018-05-07 23:04:42 139637723433088 [ERROR] Could not open mysql.plugin table. Some plugins may be not loaded
May 07 23:04:42 node3.test.com mysqld[1501]: 2018-05-07 23:04:42 139637723433088 [ERROR] Can't open and lock privilege tables: Table 'mysql.servers' doesn't exist
May 07 23:04:42 node3.test.com mysqld[1501]: 2018-05-07 23:04:42 139637723433088 [Note] Server socket created on IP: '::'.
May 07 23:04:42 node3.test.com mysqld[1501]: 2018-05-07 23:04:42 139637723433088 [ERROR] Fatal error: Can't open and lock privilege tables: Table 'mysql.user' doesn't exist
May 07 23:04:42 node3.test.com systemd[1]: mariadb.service: main process exited, code=exited, status=1/FAILURE
May 07 23:04:42 node3.test.com systemd[1]: Failed to start MariaDB database server.
我查阅以前的笔记，发现在使用innobackupex做数据恢复时，由于其本质相当于数据库数据文件的拷贝操作，因此在innobackupex --copy-back命令执行成功后，需要将数据文件的属主属组信息全部修改为mysql。
果然，当前数据目录下的各文件属主属组信息如下：
[root@node3 app]#ll /var/lib/mysql/
total 188456
-rw-rw---- 1 mysql mysql 16384 May 7 23:00 aria_log.00000001
-rw-rw---- 1 mysql mysql 52 May 7 23:00 aria_log_control
-rw-r----- 1 root root 5239 May 7 22:58 ib_buffer_pool
-rw-r----- 1 root root 79691776 May 7 22:58 ibdata1
-rw-r----- 1 root root 50331648 May 7 22:58 ib_logfile0
-rw-r----- 1 root root 50331648 May 7 22:58 ib_logfile1
-rw-r----- 1 root root 12582912 May 7 22:58 ibtmp1
drwxr-x--- 2 root root 4096 May 7 22:58 mysql
drwxr-x--- 2 root root 20 May 7 22:58 performance_schema
drwxr-x--- 2 root root 20 May 7 22:58 test
drwxr-x--- 2 root root 4096 May 7 22:58 wpdb
-rw-r----- 1 root root 418 May 7 22:58 xtrabackup_info
于是我使用chown命令修改数据目录属主属组：
[root@node3 app]#chown mysql:mysql /var/lib/mysql/*
[root@node3 app]#ll /var/lib/mysql/
total 188456
-rw-rw---- 1 mysql mysql 16384 May 7 23:00 aria_log.00000001
-rw-rw---- 1 mysql mysql 52 May 7 23:00 aria_log_control
-rw-r----- 1 mysql mysql 5239 May 7 22:58 ib_buffer_pool
-rw-r----- 1 mysql mysql 79691776 May 7 22:58 ibdata1
-rw-r----- 1 mysql mysql 50331648 May 7 22:58 ib_logfile0
-rw-r----- 1 mysql mysql 50331648 May 7 22:58 ib_logfile1
-rw-r----- 1 mysql mysql 12582912 May 7 22:58 ibtmp1
drwxr-x--- 2 mysql mysql 4096 May 7 22:58 mysql
drwxr-x--- 2 mysql mysql 20 May 7 22:58 performance_schema
drwxr-x--- 2 mysql mysql 20 May 7 22:58 test
drwxr-x--- 2 mysql mysql 4096 May 7 22:58 wpdb
-rw-r----- 1 mysql mysql 418 May 7 22:58 xtrabackup_info
似乎看起来一切应该正常了，于是我再次重新启动mysqld服务，然而还是失败。仍然有以下报错信息：
May 07 23:04:42 node3.test.com mysqld[1501]: 2018-05-07 23:04:42 139637723433088 [ERROR] Could not open mysql.plugin table. Some plugins may be no
May 07 23:04:42 node3.test.com mysqld[1501]: 2018-05-07 23:04:42 139637723433088 [ERROR] Can't open and lock privilege tables: Table 'mysql.server
May 07 23:04:42 node3.test.com mysqld[1501]: 2018-05-07 23:04:42 139637723433088 [Note] Server socket created on IP: '::'.
May 07 23:04:42 node3.test.com mysqld[1501]: 2018-05-07 23:04:42 139637723433088 [ERROR] Fatal error: Can't open and lock privilege tables: Table
依然是提示相关的数据表文件不存在或无法打开，但是所有的数据文件都在，所以看起来应该还是权限的问题，我灵机一动，直接查看数据库‘mysql’的相关标文件的权限信息，结果发现了问题的所在：
root@node3 app]#ll /var/lib/mysql/mysql/
total 1100
-rw-r----- 1 root root 2110 May 7 22:58 columns_priv.frm
-rw-r----- 1 root root 0 May 7 22:58 columns_priv.MYD
-rw-r----- 1 root root 4096 May 7 22:58 columns_priv.MYI
-rw-r----- 1 root root 2602 May 7 22:58 column_stats.frm
-rw-r----- 1 root root 0 May 7 22:58 column_stats.MYD
-rw-r----- 1 root root 4096 May 7 22:58 column_stats.MYI
-rw-r----- 1 root root 2677 May 7 22:58 db.frm
-rw-r----- 1 root root 1896 May 7 22:58 db.MYD
-rw-r----- 1 root root 9216 May 7 22:58 db.MYI
-rw-r----- 1 root root 3683 May 7 22:58 event.frm
-rw-r----- 1 root root 0 May 7 22:58 event.MYD
-rw-r----- 1 root root 2048 May 7 22:58 event.MYI
…… ……
显然，前面我修改数据库目录的属主属组方式有误，并没有递归修改子目录下文件的属主属组。
知道问题就好办了，再次修改数据库目录的属主属组，并重新启动msyqld服务成功：
[root@node3 app]#chown -R mysql:mysql /var/lib/mysql/*
[root@node3 app]#ll /var/lib/mysql/mysql/
total 1100
-rw-r----- 1 mysql mysql 2110 May 7 22:58 columns_priv.frm
-rw-r----- 1 mysql mysql 0 May 7 22:58 columns_priv.MYD
-rw-r----- 1 mysql mysql 4096 May 7 22:58 columns_priv.MYI
-rw-r----- 1 mysql mysql 2602 May 7 22:58 column_stats.frm
-rw-r----- 1 mysql mysql 0 May 7 22:58 column_stats.MYD
-rw-r----- 1 mysql mysql 4096 May 7 22:58 column_stats.MYI
-rw-r----- 1 mysql mysql 2677 May 7 22:58 db.frm
-rw-r----- 1 mysql mysql 1896 May 7 22:58 db.MYD
-rw-r----- 1 mysql mysql 9216 May 7 22:58 db.MYI
-rw-r----- 1 mysql mysql 3683 May 7 22:58 event.frm
-rw-r----- 1 mysql mysql 0 May 7 22:58 event.MYD
-rw-r----- 1 mysql mysql 2048 May 7 22:58 event.MYI
…… ……
[root@node3 app]#systemctl start mysqld
一个简单的“-R”选项，结果导致了这么多问题，本来是自己练习中的一件小事，却反映出自己对数据恢复的流程还不太清晰，同时对命令的运用也不太仔细，真实够深刻的。
(责任编辑：IT)
记一次使用innobackupex做全备恢复失败的经历
在分别使用innobackupex --apply-log和innobackupex --copy-back命令成功后，相关信息如下：
[root@node3 app]#innobackupex --apply-log /app/backup/2018-05-07_22-49-42/
180507 22:57:49 innobackupex: Starting the apply-log operation
IMPORTANT: Please check that the apply-log run completes successfully.
At the end of a successful apply-log run innobackupex
prints "completed OK!".
innobackupex version 2.4.9 based on MySQL server 5.7.13 Linux (x86_64) (revision id: a467167cdd4)
xtrabackup: cd to /app/backup/2018-05-07_22-49-42/
xtrabackup: This target seems to be not prepared yet.
InnoDB: Number of pools: 1
xtrabackup: xtrabackup_logfile detected: size=8388608, start_lsn=(6986796)
xtrabackup: using the following InnoDB configuration for recovery:
…… ……
InnoDB: 5.7.13 started; log sequence number 6987285
xtrabackup: starting shutdown with innodb_fast_shutdown = 1
InnoDB: FTS optimize thread exiting.
InnoDB: Starting shutdown...
InnoDB: Shutdown completed; log sequence number 6987304
180507 22:57:54 completed OK!
[root@node3 app]#innobackupex --copy-back /app/backup/2018-05-07_22-49-42/
180507 22:58:36 innobackupex: Starting the copy-back operation
IMPORTANT: Please check that the copy-back run completes successfully.
At the end of a successful copy-back run innobackupex
prints "completed OK!".
innobackupex version 2.4.9 based on MySQL server 5.7.13 Linux (x86_64) (revision id: a467167cdd4)
180507 22:58:36 [01] Copying ib_logfile0 to /var/lib/mysql/ib_logfile0
180507 22:58:36 [01] ...done
…… ……
180507 22:58:38 [01] Copying ./xtrabackup_info to /var/lib/mysql/xtrabackup_info
180507 22:58:38 [01] ...done
180507 22:58:38 [01] Copying ./ibtmp1 to /var/lib/mysql/ibtmp1
180507 22:58:38 [01] ...done
180507 22:58:38 completed OK!
数据恢复按理说是成功了，于是我就直接启动mysqld服务，但是：
[root@node3 app]#systemctl restart mysql
Job for mariadb.service failed because the control process exited with error code. See "systemctl status mariadb.service" and "journalctl -xe" for details.
服务启动失败！同时有很多诸如以下的报错信息：
May 07 23:04:42 node3.test.com mysqld[1501]: 2018-05-07 23:04:42 139637723433088 [ERROR] Could not open mysql.plugin table. Some plugins may be not loaded
May 07 23:04:42 node3.test.com mysqld[1501]: 2018-05-07 23:04:42 139637723433088 [ERROR] Can't open and lock privilege tables: Table 'mysql.servers' doesn't exist
May 07 23:04:42 node3.test.com mysqld[1501]: 2018-05-07 23:04:42 139637723433088 [Note] Server socket created on IP: '::'.
May 07 23:04:42 node3.test.com mysqld[1501]: 2018-05-07 23:04:42 139637723433088 [ERROR] Fatal error: Can't open and lock privilege tables: Table 'mysql.user' doesn't exist
May 07 23:04:42 node3.test.com systemd[1]: mariadb.service: main process exited, code=exited, status=1/FAILURE
May 07 23:04:42 node3.test.com systemd[1]: Failed to start MariaDB database server.
我查阅以前的笔记，发现在使用innobackupex做数据恢复时，由于其本质相当于数据库数据文件的拷贝操作，因此在innobackupex --copy-back命令执行成功后，需要将数据文件的属主属组信息全部修改为mysql。
果然，当前数据目录下的各文件属主属组信息如下：
[root@node3 app]#ll /var/lib/mysql/
total 188456
-rw-rw---- 1 mysql mysql 16384 May 7 23:00 aria_log.00000001
-rw-rw---- 1 mysql mysql 52 May 7 23:00 aria_log_control
-rw-r----- 1 root root 5239 May 7 22:58 ib_buffer_pool
-rw-r----- 1 root root 79691776 May 7 22:58 ibdata1
-rw-r----- 1 root root 50331648 May 7 22:58 ib_logfile0
-rw-r----- 1 root root 50331648 May 7 22:58 ib_logfile1
-rw-r----- 1 root root 12582912 May 7 22:58 ibtmp1
drwxr-x--- 2 root root 4096 May 7 22:58 mysql
drwxr-x--- 2 root root 20 May 7 22:58 performance_schema
drwxr-x--- 2 root root 20 May 7 22:58 test
drwxr-x--- 2 root root 4096 May 7 22:58 wpdb
-rw-r----- 1 root root 418 May 7 22:58 xtrabackup_info
于是我使用chown命令修改数据目录属主属组：
[root@node3 app]#chown mysql:mysql /var/lib/mysql/*
[root@node3 app]#ll /var/lib/mysql/
total 188456
-rw-rw---- 1 mysql mysql 16384 May 7 23:00 aria_log.00000001
-rw-rw---- 1 mysql mysql 52 May 7 23:00 aria_log_control
-rw-r----- 1 mysql mysql 5239 May 7 22:58 ib_buffer_pool
-rw-r----- 1 mysql mysql 79691776 May 7 22:58 ibdata1
-rw-r----- 1 mysql mysql 50331648 May 7 22:58 ib_logfile0
-rw-r----- 1 mysql mysql 50331648 May 7 22:58 ib_logfile1
-rw-r----- 1 mysql mysql 12582912 May 7 22:58 ibtmp1
drwxr-x--- 2 mysql mysql 4096 May 7 22:58 mysql
drwxr-x--- 2 mysql mysql 20 May 7 22:58 performance_schema
drwxr-x--- 2 mysql mysql 20 May 7 22:58 test
drwxr-x--- 2 mysql mysql 4096 May 7 22:58 wpdb
-rw-r----- 1 mysql mysql 418 May 7 22:58 xtrabackup_info
似乎看起来一切应该正常了，于是我再次重新启动mysqld服务，然而还是失败。仍然有以下报错信息：
May 07 23:04:42 node3.test.com mysqld[1501]: 2018-05-07 23:04:42 139637723433088 [ERROR] Could not open mysql.plugin table. Some plugins may be no
May 07 23:04:42 node3.test.com mysqld[1501]: 2018-05-07 23:04:42 139637723433088 [ERROR] Can't open and lock privilege tables: Table 'mysql.server
May 07 23:04:42 node3.test.com mysqld[1501]: 2018-05-07 23:04:42 139637723433088 [Note] Server socket created on IP: '::'.
May 07 23:04:42 node3.test.com mysqld[1501]: 2018-05-07 23:04:42 139637723433088 [ERROR] Fatal error: Can't open and lock privilege tables: Table
依然是提示相关的数据表文件不存在或无法打开，但是所有的数据文件都在，所以看起来应该还是权限的问题，我灵机一动，直接查看数据库‘mysql’的相关标文件的权限信息，结果发现了问题的所在：
root@node3 app]#ll /var/lib/mysql/mysql/
total 1100
-rw-r----- 1 root root 2110 May 7 22:58 columns_priv.frm
-rw-r----- 1 root root 0 May 7 22:58 columns_priv.MYD
-rw-r----- 1 root root 4096 May 7 22:58 columns_priv.MYI
-rw-r----- 1 root root 2602 May 7 22:58 column_stats.frm
-rw-r----- 1 root root 0 May 7 22:58 column_stats.MYD
-rw-r----- 1 root root 4096 May 7 22:58 column_stats.MYI
-rw-r----- 1 root root 2677 May 7 22:58 db.frm
-rw-r----- 1 root root 1896 May 7 22:58 db.MYD
-rw-r----- 1 root root 9216 May 7 22:58 db.MYI
-rw-r----- 1 root root 3683 May 7 22:58 event.frm
-rw-r----- 1 root root 0 May 7 22:58 event.MYD
-rw-r----- 1 root root 2048 May 7 22:58 event.MYI
…… ……
显然，前面我修改数据库目录的属主属组方式有误，并没有递归修改子目录下文件的属主属组。
知道问题就好办了，再次修改数据库目录的属主属组，并重新启动msyqld服务成功：
[root@node3 app]#chown -R mysql:mysql /var/lib/mysql/*
[root@node3 app]#ll /var/lib/mysql/mysql/
total 1100
-rw-r----- 1 mysql mysql 2110 May 7 22:58 columns_priv.frm
-rw-r----- 1 mysql mysql 0 May 7 22:58 columns_priv.MYD
-rw-r----- 1 mysql mysql 4096 May 7 22:58 columns_priv.MYI
-rw-r----- 1 mysql mysql 2602 May 7 22:58 column_stats.frm
-rw-r----- 1 mysql mysql 0 May 7 22:58 column_stats.MYD
-rw-r----- 1 mysql mysql 4096 May 7 22:58 column_stats.MYI
-rw-r----- 1 mysql mysql 2677 May 7 22:58 db.frm
-rw-r----- 1 mysql mysql 1896 May 7 22:58 db.MYD
-rw-r----- 1 mysql mysql 9216 May 7 22:58 db.MYI
-rw-r----- 1 mysql mysql 3683 May 7 22:58 event.frm
-rw-r----- 1 mysql mysql 0 May 7 22:58 event.MYD
-rw-r----- 1 mysql mysql 2048 May 7 22:58 event.MYI
…… ……
[root@node3 app]#systemctl start mysqld
一个简单的“-R”选项，结果导致了这么多问题，本来是自己练习中的一件小事，却反映出自己对数据恢复的流程还不太清晰，同时对命令的运用也不太仔细，真实够深刻的。
(责任编辑：IT) |