寄稿しました。
もくじ
どっちを使う?
- XtraBackup
レプリケーションが行われているシステム。
WEBサービス。1秒も止められないようなもの。1秒で利益や損失が発生するサービス。
XtraBackup, mysqldumpの併用しておく。 - mysqldump
業務アプリ。深夜や早朝、お客さんの業務が止まる時間のあるシステム。
バイナリログは出力しておくにしても、最悪、当日の早朝や深夜のどちらかのチェックポイントにデータが戻っても良いもの、ブログとか。
ロールフォワードするのでバイナリはもちろん出しておきます。
# vi /etc/my.cnf [mysqld] # # Remove leading # and set to the amount of RAM for the most important data # cache in MySQL. Start at 70% of total RAM for dedicated server, else 10%. # innodb_buffer_pool_size = 128M # # Remove leading # to turn on a very important data integrity option: logging # changes to the binary log between backups. # log_bin # # Remove leading # to set options mainly useful for reporting servers. # The server defaults are faster for transactions and fast SELECTs. # Adjust sizes as needed, experiment to find the optimal values. # join_buffer_size = 128M # sort_buffer_size = 2M # read_rnd_buffer_size = 2M datadir=/var/lib/mysql socket=/var/lib/mysql/mysql.sock binlog-do-db = test_db binlog-ignore-db = mysql server-id = 1 log-bin = mysql-bin relay-log = relay-log #bind-address = 0.0.0.0 expire_logs_days = 10 max_binlog_size = 128M binlog_format = mixed character-set-server = utf8 default_password_lifetime = 0 # Disabling symbolic-links is recommended to prevent assorted security risks symbolic-links=0 log-error=/var/log/mysqld.log pid-file=/var/run/mysqld/mysqld.pid
この記事の主題とは関係ないけども、
[mysqld] log_bin = /var/log/mysql log_slave_updates expire_log_days = 20
レプリケーションするならスレーブでもバイナリを出しておくこと。
この記事の目的
MySQLの運用において、リストアが問題になります。XtraBackupとmysqldumpでリストア時間を計測しました。
環境
- 1CPU 3.30GHz
- メモリ8GB
- バックアップ対象DB容量:3.5GB
- CentOS7
先に結論
バックアップ | リストア | |
mysqldump | 48秒 | 3分23秒 |
xtrabackup | 29秒 | 25秒 |
mysqldumpがSQLに対して、xtrabackupは解凍なので当たり前っちゃ当たり前ですが恐ろしい差がでますね。レプリケーションとかしているとリストアしている間の時間はシビアなので速いにこしたことはないのです。
MySQLで普通にmysqldumpする
普通にmysqldumpします。
# time mysqldump -u root -p --all-databases --single-transaction --master-data=2 --flush-logs > alldump20171129.sql Enter password: real 0m48.273s user 0m17.952s sys 0m2.024s
48秒で出来ました。
リストア
# time mysql -u root -p < alldump20171129.sql Enter password: real 3m23.844s user 0m19.109s sys 0m1.608s
3分23秒
Xtrabackupのインストール
# yum install gpg
# yum install https://www.percona.com/downloads/XtraBackup/Percona-XtraBackup-2.4.8/binary/redhat/7/x86_64/percona-xtrabackup-24-2.4.8-1.el7.x86_64.rpm インストール: percona-xtrabackup-24.x86_64 0:2.4.8-1.el7 依存性関連をインストールしました: libev.x86_64 0:4.15-7.el7 perl-Digest.noarch 0:1.17-245.el7 perl-Digest-MD5.x86_64 0:2.52-3.el7
バックアップディレクトリの作成
# mkdir -p /backupdb/xtrabackup
バックアップ
# time /usr/bin/innobackupex --user root --password パスワード --no-lock /backupdb/xtrabackup xtrabackup: Transaction log of lsn (61580269) to (61580278) was copied. 171129 18:59:34 completed OK! real 0m29.636s user 0m0.241s sys 0m2.765s
29秒
いきなり!ロールフォワード
XtrraBackupがめちゃ速!という結論は出ていますし、会社記事作成用とはいえ、せっかくDBのバックアップとリストアする作業を設けたので、ロールフォワードの訓練もしておくことにします。
ロールフォワード(前進復帰)
例えば、夕方17時に障害が発生し、朝5時にバックアップした復旧ポイントにデータをリストアすることをロールバック。ロールバックした地点から夕方17時まで、更新処理を改めて行うことで復旧することをロールフォワードといいます。
ロールフォワードのシナリオ
- データ入力する作業中に誤ってデータの削除をしてしまっている事に後で気付いた!
- そこでロールバック&ロールフォワードによる復旧!
茶番にお付き合い下さい。
大切なデータの追加1
INSERT INTO `msg` (`msg_id`, `msg`) VALUES ('999991', '遅いじゃないか・・ミッターマイヤー。'); INSERT INTO `msg` (`msg_id`, `msg`) VALUES ('999992', '卿がくるまで、生きていようと思ったのに、間に・合わないじゃないか・・。');
大切なデータの追加2
DELETE FROM `msg` WHERE `msg`.`msg_id` = 2
大切なデータの追加3
INSERT INTO `msg` (`msg_id`, `msg`) VALUES ('999993', '疾風ウォルフの名に恥じるじゃないか。。');
…!!!
サンプルデータの追加したと思ったら消してしまっています。
DELETE FROM `msg` WHERE `msg`.`msg_id` = 2
大変ですね。
緊急メンテナンスモードにしましょう。
サンプルデータの追加2をなかったことにしつつ、追加1と追加3は反映させた状態で復旧させなくてはいけません。
メンテナンスモードにして復旧するというシナリオです。
リストア
MySQLを止めます。
# systemctl stop mysqld
旧ファイル退避。mysql.oldにバイナリログも退避される
# mv /var/lib/mysql /var/lib/mysql.old # mkdir /var/lib/mysql
バックアップディレクトリの確認
# ls -laht /backupdb/xtrabackup 合計 0 drwxr-x--- 8 root root 267 11月 29 19:16 2017-11-29_19-15-51 drwxr-xr-x 3 root root 33 11月 29 19:15 . drwxr-xr-x 3 root root 24 11月 29 19:07 ..
バイナリのポジションの把握
# cat /backupdb/xtrabackup/2017-11-29_19-15-51/xtrabackup_binlog_info mysql-bin.000001 154
mysql-bin.000001のファイルの154から見ればいいことがわかります。
リストアします。
# time /usr/bin/innobackupex --copy-back /backupdb/xtrabackup/2017-11-29_19-15-51 171129 17:53:07 completed OK! real 0m25.178s user 0m0.022s sys 0m2.795s
25秒。
速いですね!
感動している場合じゃありません、復旧しなければ!!
binlogの具合を見てみよう。
# mysqlbinlog /var/lib/mysql.old/mysql-bin.000001 /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; # at 4 #171129 19:14:18 server id 1 end_log_pos 123 CRC32 0xea09430a Start: binlog v 4, server v 5.7.20-log created 171129 19:14:18 at startup ROLLBACK/*!*/; BINLOG ' eogeWg8BAAAAdwAAAHsAAAAAAAQANS43LjIwLWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA AAAAAAAAAAAAAAAAAAB6iB5aEzgNAAgAEgAEBAQEEgAAXwAEGggAAAAICAgCAAAACgoKKioAEjQA AQpDCeo= '/*!*/; # at 123 #171129 19:14:18 server id 1 end_log_pos 154 CRC32 0x657305ad Previous-GTIDs # [empty] # at 154 #171129 19:24:50 server id 1 end_log_pos 219 CRC32 0x8a369a1e Anonymous_GTID last_committed=0 sequence_number=1 rbr_only=no SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/; # at 219 #171129 19:24:50 server id 1 end_log_pos 310 CRC32 0x4e906b8a Query thread_id=63 exec_time=1 error_code=0 SET TIMESTAMP=1511951090/*!*/; SET @@session.pseudo_thread_id=63/*!*/; SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/; SET @@session.sql_mode=1436549152/*!*/; SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/; /*!\C utf8mb4 *//*!*/; SET @@session.character_set_client=45,@@session.collation_connection=224,@@session.collation_server=33/*!*/; SET @@session.lc_time_names=0/*!*/; SET @@session.collation_database=DEFAULT/*!*/; BEGIN /*!*/; # at 310 #171129 19:24:50 server id 1 end_log_pos 629 CRC32 0xc383e379 Query thread_id=63 exec_time=1 error_code=0 use `test_db`/*!*/; SET TIMESTAMP=1511951090/*!*/; INSERT INTO `msg` (`msg_id`, `msg`) VALUES ('999991', '遅いじゃないか・・ミッターマイヤー。') /*!*/; # at 629 #171129 19:24:50 server id 1 end_log_pos 660 CRC32 0xdf4fc2f8 Xid = 575 COMMIT/*!*/; # at 660 #171129 19:25:57 server id 1 end_log_pos 725 CRC32 0x82b81ec8 Anonymous_GTID last_committed=1 sequence_number=2 rbr_only=no SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/; # at 725 #171129 19:25:57 server id 1 end_log_pos 816 CRC32 0x72fd2605 Query thread_id=73 exec_time=0 error_code=0 SET TIMESTAMP=1511951157/*!*/; BEGIN /*!*/; # at 816 #171129 19:25:57 server id 1 end_log_pos 1186 CRC32 0x08b147d5 Query thread_id=73 exec_time=0 error_code=0 SET TIMESTAMP=1511951157/*!*/; INSERT INTO `msg` (`msg_id`, `msg`) VALUES ('999992', '卿がくるまで、生きていようと思ったのに、間に・合わないじゃないか・・。') /*!*/; # at 1186 #171129 19:25:57 server id 1 end_log_pos 1217 CRC32 0xeed258fe Xid = 661 COMMIT/*!*/; # at 1217 #171129 19:26:25 server id 1 end_log_pos 1282 CRC32 0xf66f5e54 Anonymous_GTID last_committed=2 sequence_number=3 rbr_only=no SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/; # at 1282 #171129 19:26:25 server id 1 end_log_pos 1373 CRC32 0x70ac6c88 Query thread_id=89 exec_time=0 error_code=0 SET TIMESTAMP=1511951185/*!*/; BEGIN /*!*/; # at 1373 #171129 19:26:25 server id 1 end_log_pos 1501 CRC32 0xbc5036a8 Query thread_id=89 exec_time=0 error_code=0 SET TIMESTAMP=1511951185/*!*/; DELETE FROM `msg` WHERE `msg`.`msg_id` = 2 /*!*/; # at 1501 #171129 19:26:25 server id 1 end_log_pos 1532 CRC32 0xd54ce32e Xid = 978 COMMIT/*!*/; # at 1532 #171129 19:27:09 server id 1 end_log_pos 1597 CRC32 0x143bba6e Anonymous_GTID last_committed=3 sequence_number=4 rbr_only=no SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/; # at 1597 #171129 19:27:09 server id 1 end_log_pos 1688 CRC32 0xa554ccdb Query thread_id=99 exec_time=0 error_code=0 SET TIMESTAMP=1511951229/*!*/; BEGIN /*!*/; # at 1688 #171129 19:27:09 server id 1 end_log_pos 2010 CRC32 0xcff8cf32 Query thread_id=99 exec_time=0 error_code=0 SET TIMESTAMP=1511951229/*!*/; INSERT INTO `msg` (`msg_id`, `msg`) VALUES ('999993', '疾風ウォルフの名に恥じるじゃないか。。') /*!*/; # at 2010 #171129 19:27:09 server id 1 end_log_pos 2041 CRC32 0xeca4c678 Xid = 1078 COMMIT/*!*/; # at 2041 #171129 19:27:37 server id 1 end_log_pos 2064 CRC32 0xce9d6960 Stop SET @@SESSION.GTID_NEXT= 'AUTOMATIC' /* added by mysqlbinlog */ /*!*/; DELIMITER ; # End of log file /*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/; /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/;
わけがわからない。文字が多すぎですよね。事前知識がないと意味わからんです。
書いてある内容の解説
ヒント1.
# at 154 #171129 19:24:50 server id 1 end_log_pos 219 CRC32 0x8a369a1e Anonymous_GTID last_committed=0 sequence_number=1 rbr_only=no SET @@SESSION.GTID_NEXT= 'ANONYMOUS'/*!*/;
バイナリポジションの把握から154から見ていけばいいことがわかっています。
ヒント2.
#171129 19:26:25
上記は2017年11月29日19時26分25秒をあらわします。
ヒント3.
# at 310 #171129 19:24:50 server id 1 end_log_pos 629 CRC32 0xc383e379 Query thread_id=63 exec_time=1 error_code=0 use `test_db`/*!*/; SET TIMESTAMP=1511951090/*!*/; INSERT INTO `msg` (`msg_id`, `msg`) VALUES ('999991', '遅いじゃないか・・ミッターマイヤー。') /*!*/; # at 629
# at 数字はファイルの場所を指定していると考えてください。ポジション310と629の間にINSERTのクエリがあることがわかります。
また、事故のクエリはDELETEです、DELETEで検索すれば良いかもしれません!
DELETEで前後5行を検索します。
# mysqlbinlog /var/lib/mysql.old/mysql-bin.000001 | grep -A 5 -B 5 "DELETE" BEGIN /*!*/; # at 1373 #171129 19:26:25 server id 1 end_log_pos 1501 CRC32 0xbc5036a8 Query thread_id=89 exec_time=0 error_code=0 SET TIMESTAMP=1511951185/*!*/; DELETE FROM `msg` WHERE `msg`.`msg_id` = 2 /*!*/; # at 1501 #171129 19:26:25 server id 1 end_log_pos 1532 CRC32 0xd54ce32e Xid = 978 COMMIT/*!*/; # at 1532
あっいいですね。
ポジション1373と1501の間に問題のクエリがあることがわかります。
もしくは、事故った時間がわかれば話は早いです。
# mysqlbinlog --start-datetime="2017-11-29 17:30:00" /var/lib/mysql.old/mysql-bin.000001
時間を指定することでそこの時点からファイルを参照することが出来ます。
復旧用クエリ抽出
# mysqlbinlog --database="test_db" --start-position=154 --stop-position=1373 /var/lib/mysql.old/mysql-bin.000001 > /root/recovery_1.sql # mysqlbinlog --database="test_db" --start-position=1501 --stop-position=2041 /var/lib/mysql.old/mysql-bin.000001 > /root/recovery_2.sql
事故ったクエリを迂回するように指定することで復旧用クエリを抽出することが出来ます。
MySQLの起動
# chown -R mysql:mysql /var/lib/mysql # systemctl restart mysqld
復旧用クエリによるロールフォワード
# mysql -u root -p < /root/recovery_1.sql # mysql -u root -p < /root/recovery_2.sql
データの確認
mysql> SELECT * FROM `msg` WHERE msg_id = 2; +--------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+------+----------+---------+---------------------+ | msg_id | msg | img | girl_flg | del_flg | regdate | +--------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+------+----------+---------+---------------------+ | 2 | テスト | | 1 | 0 | 2013-06-29 21:03:59 | +--------+----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+------+----------+---------+---------------------+ 1 row in set (0.00 sec) mysql> SELECT * FROM `msg` WHERE msg_id = 999991; +--------+-------------------------------------------------------- | msg_id | msg +--------+-------------------------------------------------------- | 999991 | 遅いじゃないか・・ミッターマイヤー。 +--------+-------------------------------------------------------- 1 row in set (0.00 sec) mysql> SELECT * FROM `msg` WHERE msg_id = 999992; +--------+---------+-----------------------------------------------------------------------------------------------------------+ | msg_id | user_cd | msg | +--------+---------+-----------------------------------------------------------------------------------------------------------+ | 999992 | 999992 | 卿がくるまで、生きていようと思ったのに、間に・合わないじゃないか・・。 | +--------+---------+-----------------------------------------------------------------------------------------------------------+ 1 row in set (0.00 sec) mysql> SELECT * FROM `msg` WHERE msg_id = 999993; +--------+-----------------------------------------------------------+ | msg_id | msg | +--------+-----------------------------------------------------------+ | 999993 | 疾風ウォルフの名に恥じるじゃないか。。 | +--------+-----------------------------------------------------------+ 1 row in set (0.00 sec)
大丈夫そうですね。
無事復旧できましたね。
お疲れ様です。