sysbench 0.5のインストールと簡単な使い方
MySQLのベンチマークとしてよく利用されるsysbenchのインストールと使い方について簡単にメモ。バージョンは0.5となります。
sysbench 0.5のダウンロード
(たぶん)sysbench 0.5はWebからダウンロード出来る場所がありません。ダウンロードはlaunchpadから行います。launchpadのアカウントの作成方法は割愛しますので予めアカウント作成しておいて下さい。
$ bzr branch lp:sysbench Branched 116 revision(s). $ ls -ld sysbench drwxr-xr-x 7 hiroi10 hiroi10 4096 Jun 1 04:07 sysbench $ cd sysbench $ ls -l total 100 -rwxr-xr-x 1 hiroi10 hiroi10 3074 Jun 1 04:07 autogen.sh -rw-r--r-- 1 hiroi10 hiroi10 7585 Jun 1 04:07 ChangeLog drwxr-xr-x 2 hiroi10 hiroi10 4096 Jun 1 04:07 config -rw-r--r-- 1 hiroi10 hiroi10 11267 Jun 1 04:07 configure.ac -rw-r--r-- 1 hiroi10 hiroi10 17992 Jun 1 04:07 COPYING drwxr-xr-x 3 hiroi10 hiroi10 4096 Jun 1 04:07 doc -rwxr-xr-x 1 hiroi10 hiroi10 7122 Jun 1 04:07 install-sh drwxr-xr-x 2 hiroi10 hiroi10 4096 Jun 1 04:07 m4 -rw-r--r-- 1 hiroi10 hiroi10 840 Jun 1 04:07 Makefile.am -rwxr-xr-x 1 hiroi10 hiroi10 10266 Jun 1 04:07 missing -rwxr-xr-x 1 hiroi10 hiroi10 1988 Jun 1 04:07 mkinstalldirs -rw-r--r-- 1 hiroi10 hiroi10 3044 Jun 1 04:07 README -rw-r--r-- 1 hiroi10 hiroi10 973 Jun 1 04:07 README-WIN.txt drwxr-xr-x 5 hiroi10 hiroi10 4096 Jun 1 04:07 sysbench -rw-r--r-- 1 hiroi10 hiroi10 26 Jun 1 04:07 TODO $
コンパイルとインストール
事前にMySQL5.6.11をインストールしておいて下さい。MySQLがインストール済みであればコンパイル前までの準備はOKです。以下例はソースから/usr/local/mysql-5.6.11にインストール済みの場合です。
$ ./autogen.sh && ./configure --prefix=/usr/local/sysbench --with-mysql=/usr/local/mysql-5.6.11 $ make $ sudo make install $ /usr/local/sysbench/bin/sysbench --version sysbench 0.5 $
以上でsysbenchの使用準備は完了です。
sysbench用のデータベースとMySQLアカウントを作成する
$ /usr/local/mysql-5.6.11/bin/mysql -uroot mysql> create database sbtest; mysql> grant all on sbtest.* to sbtest@localhost identified by 'sbtest-pw'; mysql> quit $
テスト用データをロードしてみる
その前に0.5系から使われるようになった各種luaファイルをコピーしておきます。
$ pwd /home/hiroi10/sysbench/sysbench/tests/db $ mkdir /usr/local/sysbench/lua $ cp -p *.lua /usr/local/sysbench/lua
ではロードします。以下の例は
- テーブル数12
- 1テーブルの行数3750000
- 3並列でロード
となります。環境によって--num-threadsを増やすとより速くロードが行えます。なお、--num-threadsは--oltp-tables-countの約数となるようにして下さい。
$ /usr/local/sysbench/bin/sysbench \ --test=/usr/local/sysbench/lua/parallel_prepare.lua \ --db-driver=mysql \ --oltp-tables-count=12 \ --oltp-table-size=3750000 \ --num-threads=3 \ --mysql-db=sbtest \ --mysql-user=root \ --mysql-socket=/tmp/mysql-5.6.11.sock \ run $ $ ls -lh /usr/local/mysql-5.6.11/data/sbtest total 11G -rw-rw---- 1 mysql mysql 61 May 25 23:02 db.opt -rw-rw---- 1 mysql mysql 8.5K May 25 23:30 sbtest10.frm -rw-rw---- 1 mysql mysql 900M May 25 23:33 sbtest10.ibd -rw-rw---- 1 mysql mysql 8.5K May 25 23:30 sbtest11.frm -rw-rw---- 1 mysql mysql 904M May 25 23:33 sbtest11.ibd -rw-rw---- 1 mysql mysql 8.5K May 25 23:30 sbtest12.frm -rw-rw---- 1 mysql mysql 900M May 25 23:33 sbtest12.ibd -rw-rw---- 1 mysql mysql 8.5K May 25 23:22 sbtest1.frm -rw-rw---- 1 mysql mysql 900M May 25 23:25 sbtest1.ibd -rw-rw---- 1 mysql mysql 8.5K May 25 23:22 sbtest2.frm -rw-rw---- 1 mysql mysql 900M May 25 23:25 sbtest2.ibd -rw-rw---- 1 mysql mysql 8.5K May 25 23:22 sbtest3.frm -rw-rw---- 1 mysql mysql 900M May 25 23:25 sbtest3.ibd -rw-rw---- 1 mysql mysql 8.5K May 25 23:25 sbtest4.frm -rw-rw---- 1 mysql mysql 900M May 25 23:28 sbtest4.ibd -rw-rw---- 1 mysql mysql 8.5K May 25 23:25 sbtest5.frm -rw-rw---- 1 mysql mysql 900M May 25 23:28 sbtest5.ibd -rw-rw---- 1 mysql mysql 8.5K May 25 23:25 sbtest6.frm -rw-rw---- 1 mysql mysql 900M May 25 23:28 sbtest6.ibd -rw-rw---- 1 mysql mysql 8.5K May 25 23:28 sbtest7.frm -rw-rw---- 1 mysql mysql 900M May 25 23:31 sbtest7.ibd -rw-rw---- 1 mysql mysql 8.5K May 25 23:27 sbtest8.frm -rw-rw---- 1 mysql mysql 900M May 25 23:31 sbtest8.ibd -rw-rw---- 1 mysql mysql 8.5K May 25 23:27 sbtest9.frm -rw-rw---- 1 mysql mysql 900M May 25 23:31 sbtest9.ibd $
ということでベンチマークを実行する準備が完了です。
なお、具体的に計ってませんがsysbench 0.4.12と比較すると並列にロード出来るのを抜きにしてもロードにかかる時間は0.5の方がかなり速いと感じました。
ベンチマークの実行
以下は自分がやってる実行例です。以下例はread-onlyですが--oltp-read-onlyをoffにすればread-writeのテストになります。(2013/06/13 オプション間違いがあったので直しました orz)
$ cat ./ro-bench.sh #!/bin/sh threads='8 16 32 64 128 256 512 1024' DIR="テストケース名" [ ! -d $DIR ] && mkdir $DIR cp -pi /usr/local/mysql-5.6.11/etc/my.cnf $DIR/. for thread in $threads; do echo "==== $thread ====" /usr/local/sysbench/bin/sysbench \ --test=/usr/local/sysbench/lua/oltp.lua \ --rand-init=on \ --db-driver=mysql \ --oltp-table-size=3750000 \ --rand-type=uniform \ --oltp-read-only=on \ --oltp-tables-count=12 \ --mysql-db=sbtest \ --mysql-user=sbtest \ --mysql-password=sbtest-pw \ --mysql-socket=/tmp/mysql-5.6.11.sock \ --max-time=180 \ --max-requests=0 \ --num-threads=$thread \ run | tee $DIR/ro-$thread sleep 30 done $
実際にベンチマークを取得する場合は事前にread-only、1024スレッドで60〜90秒程度を実行してバッファプールにデータ・インデックスの情報を載せてから実行しています。
$ /usr/local/sysbench/bin/sysbench \ > --test=/usr/local/sysbench/lua/oltp.lua \ > --rand-init=on \ > --db-driver=mysql \ > --oltp-table-size=3750000 \ > --rand-type=uniform \ > --oltp-read-only=on \ > --oltp-tables-count=12 \ > --mysql-user=sbtest \ > --mysql-password=sbtest-pw \ > --mysql-db=sbtest \ > --mysql-socket=/tmp/mysql-5.6.11.sock \ > --max-time=60 \ > --max-requests=0 \ > --num-threads=1024 \ > run sysbench 0.5: multi-threaded system evaluation benchmark Running the test with following options: Number of threads: 1024 Random number generator seed is 0 and will be ignored Threads started! OLTP test statistics: queries performed: read: 4549314 write: 0 other: 649902 total: 5199216 transactions: 324951 (5407.94 per sec.) deadlocks: 0 (0.00 per sec.) read/write requests: 4549314 (75711.09 per sec.) other operations: 649902 (10815.87 per sec.) General statistics: total time: 60.0878s total number of events: 324951 total time taken by event execution: 61384.6368s response time: min: 3.38ms avg: 188.90ms max: 1629.68ms approx. 95 percentile: 511.43ms Threads fairness: events (avg/stddev): 317.3350/8.68 execution time (avg/stddev): 59.9459/0.08 $
gtidを使用した環境でのmysqldump
以前の日記Global Transaction IDを使ってレプリケーション構成とした際の制限でmysqldumpから新規にスレーブを作ろうとするとgtidが記録されなくてバイナリログ使わないとダメ、と書いたんだけど、5.6.10で試したら普通にスレーブを作成可能だったので訂正も含めて書きます。
よくあるmysqldump
MySQL5.5系まででgtidが存在しない環境では良く以下のようにmysqldumpを実行しているかと思います(InnoDBのみ利用の場合)。
# mysqldump --all-databases --single-transaction --master-data=2 > /path/to/dir/dump または # mysqldump --all-databases --single-transaction --master-data=2 | gzip > /path/to/dir/dump.gz イベントスケジューラーとかその他色々使ってる場合 # mysqldump --all-databases --single-transaction --master-data=2 --triggers --routines --events > /path/to/dir/dump
なお、gtidを利用した環境では--triggers --routines --eventsオプションを使用しない場合は以下のようにWarningが出力されます。
# mysqldump --all-databases --single-transaction --master-data=2 > /tmp/dump Warning: A partial dump from a server that has GTIDs will by default include the GTIDs of all transactions, even those that changed suppressed parts of the database. If you don't want to restore GTIDs, pass --set-gtid-purged=OFF. To make a complete dump, pass --all-databases --triggers --routines --events. #
gtid環境でmysqldumpを取得した場合のダンプファイル
上記のmysqldump実行例の以下内容でダンプを取得します。
# mysqldump --all-databases --single-transaction --master-data=2 --triggers --routines --events > /path/to/dir/dump
ダンプファイルの中身を覗いてみます。
# mysqldump --all-databases --single-transaction --master-data=2 --triggers --routines --events > /tmp/dump # head -30 /tmp/dump -- MySQL dump 10.13 Distrib 5.6.10, for Linux (x86_64) -- -- Host: localhost Database: -- ------------------------------------------------------ -- Server version 5.6.10-log /*!40101 SET @OLD_CHARACTER_SET_CLIENT=@@CHARACTER_SET_CLIENT */; /*!40101 SET @OLD_CHARACTER_SET_RESULTS=@@CHARACTER_SET_RESULTS */; /*!40101 SET @OLD_COLLATION_CONNECTION=@@COLLATION_CONNECTION */; /*!40101 SET NAMES utf8 */; /*!40103 SET @OLD_TIME_ZONE=@@TIME_ZONE */; /*!40103 SET TIME_ZONE='+00:00' */; /*!40014 SET @OLD_UNIQUE_CHECKS=@@UNIQUE_CHECKS, UNIQUE_CHECKS=0 */; /*!40014 SET @OLD_FOREIGN_KEY_CHECKS=@@FOREIGN_KEY_CHECKS, FOREIGN_KEY_CHECKS=0 */; /*!40101 SET @OLD_SQL_MODE=@@SQL_MODE, SQL_MODE='NO_AUTO_VALUE_ON_ZERO' */; /*!40111 SET @OLD_SQL_NOTES=@@SQL_NOTES, SQL_NOTES=0 */; SET @MYSQLDUMP_TEMP_LOG_BIN = @@SESSION.SQL_LOG_BIN; SET @@SESSION.SQL_LOG_BIN= 0; -- -- GTID state at the beginning of the backup -- SET @@GLOBAL.GTID_PURGED='71803be2-7816-11e2-8c99-5254003e1cec:1-665'; -- -- Position to start replication or point-in-time recovery from -- -- CHANGE MASTER TO MASTER_LOG_FILE='mysql-bin.000006', MASTER_LOG_POS=197930;
ここで見慣れない以下内容が記録されています。
SET @@GLOBAL.GTID_PURGED='71803be2-7816-11e2-8c99-5254003e1cec:1-665';
gtid関連のパラメータとして、MySQL5.6.10では以下パラメータが存在しています。以下はMaster側のダンプを取得したMySQLの内容です。
mysql> show global variables like '%gtid%'; +--------------------------+--------------------------------------------+ | Variable_name | Value | +--------------------------+--------------------------------------------+ | enforce_gtid_consistency | ON | | gtid_executed | 71803be2-7816-11e2-8c99-5254003e1cec:1-665 | | gtid_mode | ON | | gtid_owned | | | gtid_purged | | +--------------------------+--------------------------------------------+ 5 rows in set (0.00 sec) mysql> show variables like '%gtid%'; +--------------------------+-----------+ | Variable_name | Value | +--------------------------+-----------+ | enforce_gtid_consistency | ON | | gtid_executed | | | gtid_mode | ON | | gtid_next | AUTOMATIC | | gtid_owned | | | gtid_purged | | +--------------------------+-----------+ 6 rows in set (0.00 sec) mysql>
global無しを書いたのはgtid_nextはsessionのみのパラメータのためです。
リストアしてみる
今回ポイントとなるのはgtid_executedとgtid_purgedの2つ。先に記載のダンプファイルの内容から、リストアした場合はgtid_purgedに値が設定されることが分かります。実際に空の、新しく立ち上げたMySQLへリストアを行います。
まずはリストア前のgtid関連のパラメータの状態
mysql> show global variables like '%gtid%'; +--------------------------+-------+ | Variable_name | Value | +--------------------------+-------+ | enforce_gtid_consistency | ON | | gtid_executed | | | gtid_mode | ON | | gtid_owned | | | gtid_purged | | +--------------------------+-------+ 5 rows in set (0.00 sec) mysql>
リストアを行って確認します。
# mysql < /tmp/dump # mysql mysql> show global variables like '%gtid%'; +--------------------------+--------------------------------------------+ | Variable_name | Value | +--------------------------+--------------------------------------------+ | enforce_gtid_consistency | ON | | gtid_executed | 71803be2-7816-11e2-8c99-5254003e1cec:1-665 | | gtid_mode | ON | | gtid_owned | | | gtid_purged | 71803be2-7816-11e2-8c99-5254003e1cec:1-665 | +--------------------------+--------------------------------------------+ 5 rows in set (0.00 sec) mysql>
gtid_executedをgtid_purgedがセットされました。ダンプファイルに書いてあったのはgtid_purgedだけだったのに？
では公式ドキュメントのgtid_purgedとgtid_executedを見てみましょう。以下ざっくりと。
- gtid_executed
- 適当にまとめると、globalスコープの場合はgtid_executedに書かれてるgtidまでバイナリログに書いてあるよ、って事だと思います。read_onlyなパラメータで空にしたいならreset master;実行してね。5.6.9より前はgtid_doneってパラメータ名だったよ。
- gtid_purged
- こちらも適当にまとめると、gtid_purgedに書かれているgtidまではバイナリログから削除されてるよ。5.6.9より前はgtid_lostってパラメータ名。gtid_executedが空の場合だけset可能だよ。
なんか訳すと矛盾してるような気分になりますが、gtid_executedは設定されているgtidまでは実行済みだよってことだし、新規にダンプファイルから上記の流れでスレーブを作った場合はバイナリログにリストアされた内容は記録されていなかったりします。
# mysqlbinlog ./mysql-bin.000004 /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/; /*!40019 SET @@session.max_insert_delayed_threads=0*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; # at 4 #130309 2:22:35 server id 239 end_log_pos 120 CRC32 0x4fbf920d Start: binlog v 4, server v 5.6.10-log created 130309 2:22:35 # Warning: this binlog is either in use or was not closed properly. BINLOG ' Wx46UQ/vAAAAdAAAAHgAAAABAAQANS42LjEwLWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXAAEGggAAAAICAgCAAAACgoKGRkAAQ2S v08= '/*!*/; # at 120 #130309 2:22:35 server id 239 end_log_pos 191 CRC32 0x28155e76 Previous-GTIDs # 71803be2-7816-11e2-8c99-5254003e1cec:1-665 DELIMITER ; # End of log file ROLLBACK /* added by mysqlbinlog */; /*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/; /*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=0*/; #
なんで？と思われた方、上の方で書いたダンプファイルのhead -30の結果を再度見てみましょう。必要なポイントだけ抜粋したのが以下になります。
SET @MYSQLDUMP_TEMP_LOG_BIN = @@SESSION.SQL_LOG_BIN; SET @@SESSION.SQL_LOG_BIN= 0;
SQL_LOG_BIN=0が発行されています。よってリストアで発行された更新処理はバイナリログに記録されません。gtid_purgedがgtid_executedが同じなのは間違いではないことが分かります。
ということでスレーブではgtid_executedに設定されているgtidまで更新内容が反映済みという状態となります。この状態でchange master toでmaster_auto_position=1でレプリケーションを開始します。
mysql> change master to master_host='192.168.1.237', master_user='repl', master_password='repl-pw', master_auto_position=1; Query OK, 0 rows affected, 2 warnings (0.03 sec) mysql> show slave status\G *************************** 1. row *************************** Slave_IO_State: Master_Host: 192.168.1.237 Master_User: repl Master_Port: 3306 Connect_Retry: 60 Master_Log_File: Read_Master_Log_Pos: 4 Relay_Log_File: mysql-relay-bin.000001 Relay_Log_Pos: 4 Relay_Master_Log_File: Slave_IO_Running: No Slave_SQL_Running: No Replicate_Do_DB: Replicate_Ignore_DB: Replicate_Do_Table: Replicate_Ignore_Table: Replicate_Wild_Do_Table: Replicate_Wild_Ignore_Table: Last_Errno: 0 Last_Error: Skip_Counter: 0 Exec_Master_Log_Pos: 0 Relay_Log_Space: 151 Until_Condition: None Until_Log_File: Until_Log_Pos: 0 Master_SSL_Allowed: No Master_SSL_CA_File: Master_SSL_CA_Path: Master_SSL_Cert: Master_SSL_Cipher: Master_SSL_Key: Seconds_Behind_Master: NULL Master_SSL_Verify_Server_Cert: No Last_IO_Errno: 0 Last_IO_Error: Last_SQL_Errno: 0 Last_SQL_Error: Replicate_Ignore_Server_Ids: Master_Server_Id: 0 Master_UUID: Master_Info_File: mysql.slave_master_info SQL_Delay: 0 SQL_Remaining_Delay: NULL Slave_SQL_Running_State: Master_Retry_Count: 86400 Master_Bind: Last_IO_Error_Timestamp: Last_SQL_Error_Timestamp: Master_SSL_Crl: Master_SSL_Crlpath: Retrieved_Gtid_Set: Executed_Gtid_Set: 71803be2-7816-11e2-8c99-5254003e1cec:1-665 Auto_Position: 1 1 row in set (0.00 sec) mysql>
正しくExecuted_Gtid_Setにgtidが設定されている事が分かります。
Executed_Gtid_Set: 71803be2-7816-11e2-8c99-5254003e1cec:1-665
ではstart slave;を行いましょう。
mysql> start slave; Query OK, 0 rows affected (0.02 sec) mysql> show slave status\G *************************** 1. row *************************** Slave_IO_State: Waiting for master to send event Master_Host: 192.168.1.237 Master_User: repl Master_Port: 3306 Connect_Retry: 60 Master_Log_File: mysql-bin.000006 Read_Master_Log_Pos: 200338 Relay_Log_File: mysql-relay-bin.000007 Relay_Log_Pos: 2816 Relay_Master_Log_File: mysql-bin.000006 Slave_IO_Running: Yes Slave_SQL_Running: Yes Replicate_Do_DB: Replicate_Ignore_DB: Replicate_Do_Table: Replicate_Ignore_Table: Replicate_Wild_Do_Table: Replicate_Wild_Ignore_Table: Last_Errno: 0 Last_Error: Skip_Counter: 0 Exec_Master_Log_Pos: 200338 Relay_Log_Space: 3230 Until_Condition: None Until_Log_File: Until_Log_Pos: 0 Master_SSL_Allowed: No Master_SSL_CA_File: Master_SSL_CA_Path: Master_SSL_Cert: Master_SSL_Cipher: Master_SSL_Key: Seconds_Behind_Master: 0 Master_SSL_Verify_Server_Cert: No Last_IO_Errno: 0 Last_IO_Error: Last_SQL_Errno: 0 Last_SQL_Error: Replicate_Ignore_Server_Ids: Master_Server_Id: 237 Master_UUID: 71803be2-7816-11e2-8c99-5254003e1cec Master_Info_File: mysql.slave_master_info SQL_Delay: 0 SQL_Remaining_Delay: NULL Slave_SQL_Running_State: Slave has read all relay log; waiting for the slave I/O thread to update it Master_Retry_Count: 86400 Master_Bind: Last_IO_Error_Timestamp: Last_SQL_Error_Timestamp: Master_SSL_Crl: Master_SSL_Crlpath: Retrieved_Gtid_Set: 71803be2-7816-11e2-8c99-5254003e1cec:666-673 Executed_Gtid_Set: 71803be2-7816-11e2-8c99-5254003e1cec:1-673 Auto_Position: 1 1 row in set (0.00 sec) mysql>
問題無くレプリケーションが開始されました。良いですね。gtid環境でもmysqldumpが普通に使えます。
その他
今回は書きませんが、gtidを使ったSlaveサーバから--dump-slave=2とかでダンプを取った場合も同様に新しいSlaveを作成可能です。但し、その場合はリストアするMySQLは極力真っ新な状態の物を使う事を推奨します。クラッシュセーフなSlaveにするために以下パラメータをTABLEにしてる場合、バイナリログ、リレーログファイルの情報がダンプ元のサーバの情報になってしまうためです。
master_info_repository=TABLE relay_log_info_repository=TABLE
--dump-slaveを使う事が最初から予定されている場合は全てのMaster, Slaveで以下のようにバイナリログ、リレーログファイル名を統一しておくと良いでしょう。手間が掛からなくなります。
log-bin=mysql-bin relay_log=mysql-relay-bin
まぁ"ホスト名"-binとかの形には本来はしない方が良い(個人的にホスト名が付くのは非推奨)ので、既にちゃんと指定してるよ、という方も多いかと思います。
また、gtidを利用してない環境にリストアするためにダンプを取得する場合はmysqldumpに--set-gtid-purged=OFFを付けます。あまり無いだろうけど、あえて5.5系とか。このオプションを付ける事でgtidを使用した環境からのダンプファイルに以下内容が出力されなくなります。
SET @@GLOBAL.GTID_PURGED='71803be2-7816-11e2-8c99-5254003e1cec:1-665';
終わりに
MySQL 5.6.10ではgtidを利用した環境でもgtidを特に意識せず、mysqldumpによるダンプファイルから新規にSlaveが作成出来ます。gtid環境でネックだなぁ、と思ってた内容が一つ解消したのは個人的には嬉しい所です。
nginxのログに499(レスポンスコード)が記録される場合
最近nginxのログに499とかいう見慣れないレスポンスコードが記録されていたのでどういう状況で記録されるのか試してみた。
499が定義されてる場所
ソースコードの以下ファイルに記載されています。
- {ソース展開dir}/src/http/ngx_http_request.h
中身を抜粋したのは以下
/* * HTTP does not define the code for the case when a client closed * the connection while we are processing its request so we introduce * own code to log such situation when a client has closed the connection * before we even try to send the HTTP header to it */ #define NGX_HTTP_CLIENT_CLOSED_REQUEST 499
ということなので変なポイントでクライアントから切断されると出力されるんだろうなぁ、と当たりが付く。
出力されるか試してみる
最初割りと大きいファイルのダウンロード中にブラウザ閉じたりしたら出力されるかな、と思ったら出ない。
ってことで単純にsleepして直ぐに応答返さないようなphpを作成して、Proxy先のApacheに設置して確認する。
<?php sleep (10); print "test php";
これをindex.phpとして保存してアクセスし、test phpが出力される前にブラウザの停止、更新ボタン、そしてブラウザの停止を試してみました。
結果、以下のように499がログに記録されました。
192.168.1.240 - - [06/Mar/2013:17:12:48 +0900] "GET /index.php HTTP/1.1" 499 0 "-" "Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 6.1; Trident/4.0; SLCC2; .NET CLR 2.0.50727; .NET CLR 3.5.30729; .NET CLR 3.0.30729; MALC)" "-" 192.168.1.240 - - [06/Mar/2013:17:14:22 +0900] "GET /index.php HTTP/1.1" 499 0 "-" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.22 (KHTML, like Gecko) Chrome/25.0.1364.152 Safari/537.22" "-"
念のため複数ブラウザで確認したけど同様の結果に。
この際、nginx側は499で記録されるけど時間はかかったとしてApacheはnginxに対して応答を返すようで200でログに記録されていました。Apache側で200を返すかはその時の処理次第だと思うので、必ず200で記録する分けではないかと。実際に確認出来たわけじゃないけど…
そういう意味だと間違えてボタンとか押して、間違えた、と慌てて停止ボタンを押したとしてもProxy先のApacheまでGETなりが到達していれば処理は行われるだろうなぁ、と推測。
rowベースのレプリケーション時にステートメントもバイナリログに保存する
MySQL5.6からrowベースのレプリケーションを使用している場合でもステートメント(クエリ)をコメントとしてバイナリログに記録するオプション(binlog_rows_query_log_events)が追加されています。
このオプションを利用することでrowベースでレプリケーションされたクエリが確認し易くなります。
binlog_rows_query_log_eventsが無効な場合
mysqlbinlogコマンドに-vオプションを使う事である程度は把握が可能でした。以下例はbinlog_rows_query_log_eventsが無効な場合の表示例です。
テーブル定義と設定
mysql> show create table test\G
*************************** 1. row ***************************
Table: test
Create Table: CREATE TABLE `test` (
`id` int(11) NOT NULL AUTO_INCREMENT,
`message` varchar(255) DEFAULT NULL,
PRIMARY KEY (`id`)
) ENGINE=InnoDB DEFAULT CHARSET=utf8
1 row in set (0.00 sec)
mysql> select @@binlog_format;
+-----------------+
| @@binlog_format |
+-----------------+
| ROW |
+-----------------+
1 row in set (0.00 sec)
mysql> select @@binlog_rows_query_log_events;
+--------------------------------+
| @@binlog_rows_query_log_events |
+--------------------------------+
| 0 |
+--------------------------------+
1 row in set (0.00 sec)
mysql>
INSERTの実行
mysql> insert into test(message) values ('ROW,OFF');
Query OK, 1 row affected (0.24 sec)
mysql>
mysqlbinlogコマンドで確認
MySQL5.6環境で確認しているため、以下のようにmysqlbinlogコマンドを実行しています。
# mysqlbinlog -vv --base64-output=DECODE-ROWS -u root -R -h 127.0.0.1 --stop-never
INSERTの実行で出力された内容は以下になります。
# at 1854 #130216 17:05:21 server id 137 end_log_pos 1926 CRC32 0x69336912 Query thread_id=18 exec_time=0 error_code=0 SET TIMESTAMP=1361001921/*!*/; BEGIN /*!*/; # at 1926 #130216 17:05:21 server id 137 end_log_pos 1976 CRC32 0x8a9e741a Table_map: `test`.`test` mapped to number 71 # at 1976 #130216 17:05:21 server id 137 end_log_pos 2025 CRC32 0xe888825f Write_rows: table id 71 flags: STMT_END_F ### INSERT INTO `test`.`test` ### SET ### @1=1 /* INT meta=0 nullable=0 is_null=0 */ ### @2='ROW,OFF' /* VARSTRING(765) meta=765 nullable=1 is_null=0 */ # at 2025 #130216 17:05:21 server id 137 end_log_pos 2056 CRC32 0x402bb475 Xid = 88 COMMIT/*!*/;
正直、視認性は良くありません。UPDATEだったり列の多いテーブルだったりだと更に縦に長い出力となります。
binlog_rows_query_log_eventsが有効な場合
パラメータの変更点はbinlog_rows_query_log_eventsが有効になっただけです。
mysql> select @@binlog_rows_query_log_events; +--------------------------------+ | @@binlog_rows_query_log_events | +--------------------------------+ | 1 | +--------------------------------+ 1 row in set (0.00 sec) mysql>
INSERTの実行
mysql> insert into test(message) values ('ROW,ON');
Query OK, 1 row affected (0.00 sec)
mysql>
mysqlbinlogコマンドで確認
# at 2056
#130216 17:14:16 server id 137 end_log_pos 2128 CRC32 0xd269d2b1 Query thread_id=18 exec_time=0 error_code=0
SET TIMESTAMP=1361002456/*!*/;
BEGIN
/*!*/;
# at 2128
#130216 17:14:16 server id 137 end_log_pos 2195 CRC32 0xe407772a Rows_query
# insert into test(message) values ('ROW,ON')
# at 2195
#130216 17:14:16 server id 137 end_log_pos 2245 CRC32 0x0a47bd84 Table_map: `test`.`test` mapped to number 71
# at 2245
#130216 17:14:16 server id 137 end_log_pos 2293 CRC32 0x8be81270 Write_rows: table id 71 flags: STMT_END_F
### INSERT INTO `test`.`test`
### SET
### @1=2 /* INT meta=0 nullable=0 is_null=0 */
### @2='ROW,ON' /* VARSTRING(765) meta=765 nullable=1 is_null=0 */
# at 2293
#130216 17:14:16 server id 137 end_log_pos 2324 CRC32 0x7fadbea3 Xid = 105
COMMIT/*!*/;以下のように発行したクエリがコメントとして記載されていることがわかります。
# insert into test(message) values ('ROW,ON')デメリットとしては当然記録される情報が増えるため、バイナリログのサイズが増加することです。binlog_format=mixedの場合はめったにrowで記録されることは無いので影響は少ないのでは、と考えています。
binlog_format=rowの場合はサイズがそれなりに増加することが考えられるので5.6系であればbinlog_row_imageパラメータと合わせて設定を検討するのが良いかと。
マニュアルに記載があった内容を確認するために5.6.10 -> 5.5.30でレプリケーションを組んでみたところ、binlog_checksum=NONE、binlog_format=mixedとしたらROWベースでレプリケーションされるようなクエリを実行した際、以下のようにレプリケーションエラーとなりました。
Last_Error: Relay log read failure: Could not parse relay log event entry. The possible reasons are: the master's binary log is corrupted (you can check this by running 'mysqlbinlog' on the binary log), the slave's relay log is corrupted (you can check this by running 'mysqlbinlog' on the relay log), a network problem, or a bug in the master's or slave's MySQL code. If you want to check the master's binary log or slave's relay log, you will be able to know their names by issuing 'SHOW SLAVE STATUS' on this slave.
また、エラーとなった際のリレーログを5.5.30のmysqlbinlogコマンドで確認したところ以下のような出力がありました。
BEGIN /*!*/; # at 342 ERROR: Error in Log_event::read_log_event(): 'Sanity check failed', data_len: 51, event_type: 30 ERROR: Could not read entry at offset 391: Error in log format or read error. DELIMITER ; # End of log file ROLLBACK /* added by mysqlbinlog */;
binlog_rows_query_log_eventsがOFFだろうと上記のエラーとなったため、binlog_rows_query_log_eventsによるエラーが発生するか、発生する場合はどういった内容になるかは確認出来ていません。
メッセージからはログのフォーマットが変わった事による物のようなのでパラメータで直せるか調べてましたが今の所分からず。
なんらかの理由により5.6 -> 5.5等でレプリケーション構成を取る必要がある場合はbinlog_format=statementにしないと予期しないレプリケーションエラーに遭遇するかも可能性があります。statementにする場合は当然rowでないとレプリケーション的に安全でないクエリがスレーブに送られる場合があるので使用するクエリには注意する必要があります。<以下追記>
一応互換性を保つためのパラメータがあったもよう。
んでドキュメントに載ってないと。
log_bin_use_v1_row_eventsを有効にして試したら一律rowの場合にエラーになるわけじゃないようです。でもtimestamp型だとエラーになるのでその兼ね合いもあってまだドキュメントに載ってないのかもしれません。
一応エラー内容
Last_SQL_Error: Column 2 of table 'test.test2' cannot be converted from type '<unknown type>' to type 'timestamp'
<更に追記>
log_bin_use_v1_row_eventsを有効にしてレプリケーションエラーとならないケースでbinlog_rows_query_log_eventsを有効にしてROWベースでレプリケーションしたところ同じエラーになりました。
Last_Error: Relay log read failure: Could not parse relay log event entry. The possible reasons are: the master's binary log is corrupted (you can check this by running 'mysqlbinlog' on the binary log), the slave's relay log is corrupted (you can check this by running 'mysqlbinlog' on the relay log), a network problem, or a bug in the master's or slave's MySQL code. If you want to check the master's binary log or slave's relay log, you will be able to know their names by issuing 'SHOW SLAVE STATUS' on this slave.
MySQL5.5でtcmallocを使用する
tcmallocについて
Googleのgperftoolsに含まれるmallocライブラリ。一時MySQLで使うと速くなるよ、といった話題が出てた割に5.5系のMySQLで使う方法についてあんまり見かけないので書いてみる。
libunwindのインストール
まずはgperftoolsのコンパイルに必要なlibunwindをインストールします。
# wget http://download.savannah.gnu.org/releases/libunwind/libunwind-1.1.tar.gz # tar zxf libunwind-1.1.tar.gz # cd libunwind-1.1 # ls acinclude.m4 AUTHORS aux config configure.ac doc INSTALL Makefile.am NEWS scripts tests aclocal.m4 autom4te.cache ChangeLog configure COPYING include LICENSE Makefile.in README src TODO # ./configure # make # make install # ldconfig # ldconfig -p | grep wind libunwind.so.8 (libc6,x86-64) => /usr/local/lib/libunwind.so.8 libunwind.so (libc6,x86-64) => /usr/local/lib/libunwind.so libunwind-x86_64.so.8 (libc6,x86-64) => /usr/local/lib/libunwind-x86_64.so.8 libunwind-x86_64.so (libc6,x86-64) => /usr/local/lib/libunwind-x86_64.so libunwind-setjmp.so.0 (libc6,x86-64) => /usr/local/lib/libunwind-setjmp.so.0 libunwind-setjmp.so (libc6,x86-64) => /usr/local/lib/libunwind-setjmp.so libunwind-ptrace.so.0 (libc6,x86-64) => /usr/local/lib/libunwind-ptrace.so.0 libunwind-ptrace.so (libc6,x86-64) => /usr/local/lib/libunwind-ptrace.so libunwind-coredump.so.0 (libc6,x86-64) => /usr/local/lib/libunwind-coredump.so.0 libunwind-coredump.so (libc6,x86-64) => /usr/local/lib/libunwind-coredump.so #
gperftoolsのインストール
準備が出来た所でtcmallocが含まれるgperftoolsをインストールします。
# wget https://gperftools.googlecode.com/files/gperftools-2.0.tar.gz # tar zxf gperftools-2.0.tar.gz # cd gperftools-2.0 # ls aclocal.m4 compile configure depcomp INSTALL ltmain.sh Makefile.in NEWS README_windows.txt vsprojects AUTHORS config.guess configure.ac doc install-sh m4 missing packages src ChangeLog config.sub COPYING gperftools.sln libtool Makefile.am mkinstalldirs README TODO # # ./configure # make # make install # ldconfig # ldconfig -p | grep tcmalloc libtcmalloc_minimal_debug.so.4 (libc6,x86-64) => /usr/local/lib/libtcmalloc_minimal_debug.so.4 libtcmalloc_minimal_debug.so (libc6,x86-64) => /usr/local/lib/libtcmalloc_minimal_debug.so libtcmalloc_minimal.so.4 (libc6,x86-64) => /usr/local/lib/libtcmalloc_minimal.so.4 libtcmalloc_minimal.so (libc6,x86-64) => /usr/local/lib/libtcmalloc_minimal.so libtcmalloc_debug.so.4 (libc6,x86-64) => /usr/local/lib/libtcmalloc_debug.so.4 libtcmalloc_debug.so (libc6,x86-64) => /usr/local/lib/libtcmalloc_debug.so libtcmalloc_and_profiler.so.4 (libc6,x86-64) => /usr/local/lib/libtcmalloc_and_profiler.so.4 libtcmalloc_and_profiler.so (libc6,x86-64) => /usr/local/lib/libtcmalloc_and_profiler.so libtcmalloc.so.4 (libc6,x86-64) => /usr/local/lib/libtcmalloc.so.4 libtcmalloc.so (libc6,x86-64) => /usr/local/lib/libtcmalloc.so # # ldd /usr/local/lib/libtcmalloc.so linux-vdso.so.1 => (0x00007fffd6fff000) libunwind.so.8 => /usr/local/lib/libunwind.so.8 (0x00007f51f5209000) libpthread.so.0 => /lib64/libpthread.so.0 (0x00007f51f4fec000) libstdc++.so.6 => /usr/lib64/libstdc++.so.6 (0x00007f51f4ce5000) libm.so.6 => /lib64/libm.so.6 (0x00007f51f4a61000) libc.so.6 => /lib64/libc.so.6 (0x00007f51f46ce000) /lib64/ld-linux-x86-64.so.2 (0x0000003edb800000) libgcc_s.so.1 => /lib64/libgcc_s.so.1 (0x00007f51f44b7000) #
以上で準備完了です。
MySQLでtcmallocをロードして起動
MySQL5.5ではmy.cnfの[mysqld_safe]セクションに以下のように記載して起動することでtcmallocを使用することが出来ます。この辺りは最初の方に書いたMySQL公式サイトに記載されています。
# grep -A1 mysqld_safe my.cnf [mysqld_safe] malloc-lib=/usr/local/lib/libtcmalloc_minimal.so # /usr/local/mysql/bin/mysqld_safe & [1] 18914 # 130124 01:21:50 mysqld_safe Adding '/usr/local/lib/libtcmalloc_minimal.so' to LD_PRELOAD for mysqld 130124 01:21:50 mysqld_safe Logging to '/usr/local/mysql/data/mysqld.err'. 130124 01:21:50 mysqld_safe Starting mysqld daemon with databases from /usr/local/mysql/data # # cat /proc/`cat /usr/local/mysql/data/*.pid`/smaps | grep tcma 7fcb87a8f000-7fcb87ab5000 r-xp 00000000 fc:02 289021 /usr/local/lib/libtcmalloc_minimal.so.4.1.0 7fcb87ab5000-7fcb87cb5000 ---p 00026000 fc:02 289021 /usr/local/lib/libtcmalloc_minimal.so.4.1.0 7fcb87cb5000-7fcb87cb7000 rw-p 00026000 fc:02 289021 /usr/local/lib/libtcmalloc_minimal.so.4.1.0 #
またはソースからビルドしてMySQLを入れる場合は以下のようにcmakeのオプションで指定することで最初からtcmallocをmysqldにリンクすることも可能です。
# cmake \
-DCMAKE_INSTALL_PREFIX=/usr/local/mysql-tc \
-DWITH_MYSQLD_LDFLAGS=-ltcmalloc \
-DENABLED_LOCAL_INFILE=1 \
-DMYSQL_TCP_PORT=3306 \
-DMYSQL_UNIX_ADDR=/tmp/mysql-tc.sock \
-DWITH_EXTRA_CHARSETS=all \
-DWITH_READLINE=1
# make
# make install
#
# ldd /usr/local/mysql-tc/bin/mysqld
linux-vdso.so.1 => (0x00007fffb9780000)
libtcmalloc.so.0 => /usr/local/lib/libtcmalloc.so.0 (0x00007f2bf44fe000)
libpthread.so.0 => /lib64/libpthread.so.0 (0x000000363f400000)
librt.so.1 => /lib64/librt.so.1 (0x000000363fc00000)
libcrypt.so.1 => /lib64/libcrypt.so.1 (0x0000003641400000)
libdl.so.2 => /lib64/libdl.so.2 (0x000000363ec00000)
libstdc++.so.6 => /usr/lib64/libstdc++.so.6 (0x0000003641c00000)
libm.so.6 => /lib64/libm.so.6 (0x000000363f800000)
libgcc_s.so.1 => /lib64/libgcc_s.so.1 (0x0000003640c00000)
libc.so.6 => /lib64/libc.so.6 (0x000000363f000000)
libunwind.so.8 => /usr/local/lib/libunwind.so.8 (0x00007f2bf42e2000)
/lib64/ld-linux-x86-64.so.2 (0x000000363e800000)
libfreebl3.so => /lib64/libfreebl3.so (0x0000003641800000)
#この例だとminimalじゃないけどDWITH_MYSQLD_LDFLAGSで指定するものを変更すればminimalに出来ると思います。こちらはまだ実際に試した事無いです。
IntelのDC S3700 200GB買ってみた
気付いたらだいぶ長い事何も書いてなかったなぁ。とりあえずネタになりそうなSSD、IntelのDC S3700を購入したのでsmartctlコマンドの結果とか書いておいてみる。
販売情報についてはAkiba PC Hotline!のIntel製コントローラの新型SSDに200GB版を参照。
smartctl -Aの結果
DC S3700の結果。データセンター向けというだけあって項目多い。
# smartctl -A /dev/sdb smartctl 5.42 2011-10-20 r3458 [x86_64-linux-2.6.32-279.19.1.el6.x86_64] (local build) Copyright (C) 2002-11 by Bruce Allen, http://smartmontools.sourceforge.net === START OF READ SMART DATA SECTION === SMART Attributes Data Structure revision number: 1 Vendor Specific SMART Attributes with Thresholds: ID# ATTRIBUTE_NAME FLAG VALUE WORST THRESH TYPE UPDATED WHEN_FAILED RAW_VALUE 5 Reallocated_Sector_Ct 0x0032 100 100 000 Old_age Always - 0 9 Power_On_Hours 0x0032 100 100 000 Old_age Always - 0 12 Power_Cycle_Count 0x0032 100 100 000 Old_age Always - 7 170 Unknown_Attribute 0x0033 100 100 010 Pre-fail Always - 0 171 Unknown_Attribute 0x0032 100 100 000 Old_age Always - 0 172 Unknown_Attribute 0x0032 100 100 000 Old_age Always - 0 174 Unknown_Attribute 0x0032 100 100 000 Old_age Always - 3 175 Program_Fail_Count_Chip 0x0033 100 100 010 Pre-fail Always - 4297065085 183 Runtime_Bad_Block 0x0032 100 100 000 Old_age Always - 0 184 End-to-End_Error 0x0033 100 100 090 Pre-fail Always - 0 187 Reported_Uncorrect 0x0032 100 100 000 Old_age Always - 0 190 Airflow_Temperature_Cel 0x0022 086 086 000 Old_age Always - 14 (Min/Max 9/14) 192 Power-Off_Retract_Count 0x0032 100 100 000 Old_age Always - 3 194 Temperature_Celsius 0x0022 100 100 000 Old_age Always - 14 197 Current_Pending_Sector 0x0032 100 100 000 Old_age Always - 0 199 UDMA_CRC_Error_Count 0x003e 100 100 000 Old_age Always - 0 225 Load_Cycle_Count 0x0032 100 100 000 Old_age Always - 0 226 Load-in_Time 0x0032 100 100 000 Old_age Always - 65535 227 Torq-amp_Count 0x0032 100 100 000 Old_age Always - 4294967295 228 Power-off_Retract_Count 0x0032 100 100 000 Old_age Always - 65535 232 Available_Reservd_Space 0x0033 100 100 010 Pre-fail Always - 0 233 Media_Wearout_Indicator 0x0032 100 100 000 Old_age Always - 0 234 Unknown_Attribute 0x0032 100 100 000 Old_age Always - 0 241 Total_LBAs_Written 0x0032 100 100 000 Old_age Always - 0 242 Total_LBAs_Read 0x0032 100 100 000 Old_age Always - 0 #
比較対象としてPLEXTOR PX-256M5Sの結果。
# smartctl -A /dev/sda smartctl 5.42 2011-10-20 r3458 [x86_64-linux-2.6.32-279.19.1.el6.x86_64] (local build) Copyright (C) 2002-11 by Bruce Allen, http://smartmontools.sourceforge.net === START OF READ SMART DATA SECTION === SMART Attributes Data Structure revision number: 1 Vendor Specific SMART Attributes with Thresholds: ID# ATTRIBUTE_NAME FLAG VALUE WORST THRESH TYPE UPDATED WHEN_FAILED RAW_VALUE 1 Raw_Read_Error_Rate 0x0003 100 100 070 Pre-fail Always - 0 5 Reallocated_Sector_Ct 0x0003 100 100 000 Pre-fail Always - 0 9 Power_On_Hours 0x0002 100 100 000 Old_age Always - 2240 12 Power_Cycle_Count 0x0002 100 100 000 Old_age Always - 14 177 Wear_Leveling_Count 0x0003 100 100 000 Pre-fail Always - 5003 178 Used_Rsvd_Blk_Cnt_Chip 0x0003 100 100 000 Pre-fail Always - 0 181 Program_Fail_Cnt_Total 0x0003 100 100 000 Pre-fail Always - 0 182 Erase_Fail_Count_Total 0x0003 100 100 000 Pre-fail Always - 0 187 Reported_Uncorrect 0x0002 100 100 000 Old_age Always - 0 192 Power-Off_Retract_Count 0x0003 100 100 000 Pre-fail Always - 6 196 Reallocated_Event_Count 0x0003 100 100 000 Pre-fail Always - 0 198 Offline_Uncorrectable 0x0003 100 100 000 Pre-fail Always - 0 199 UDMA_CRC_Error_Count 0x0003 100 100 000 Pre-fail Always - 0 232 Available_Reservd_Space 0x0003 100 100 010 Pre-fail Always - 0 #
fdisk -luの結果
DC S3700の結果。
# fdisk -lu /dev/sdb Disk /dev/sdb: 200.0 GB, 200049647616 bytes 255 heads, 63 sectors/track, 24321 cylinders, total 390721968 sectors Units = sectors of 1 * 512 = 512 bytes Sector size (logical/physical): 512 bytes / 512 bytes I/O size (minimum/optimal): 512 bytes / 512 bytes Disk identifier: 0xfb0b3e26 Device Boot Start End Blocks Id System /dev/sdb1 63 390716864 195358401 83 Linux #
こちらも比較用にPLEXTOR PX-256M5Sの結果。
# fdisk -lu /dev/sda Disk /dev/sda: 256.1 GB, 256060514304 bytes 255 heads, 63 sectors/track, 31130 cylinders, total 500118192 sectors Units = sectors of 1 * 512 = 512 bytes Sector size (logical/physical): 512 bytes / 4096 bytes I/O size (minimum/optimal): 4096 bytes / 4096 bytes Disk identifier: 0x000314c6 Device Boot Start End Blocks Id System /dev/sda1 128520 2313359 1092420 82 Linux swap / Solaris /dev/sda2 * 2313360 500103449 248895045 83 Linux
DC S3700はSector sizeがlogical/physicalの両方が512bytesだけどPX-256M5Sはphysicalが4096bytes。I/O sizeも違う。
PX-256M5Sは最近多い4kセクタだけどDC S3700はパーティション切る時に意識しなくて良い512バイトセクタ。この辺りはやはりDC向けってことで意識してるのかな？ 最近のIntelのコンシューマ向けSSDのセクタサイズがどうなってるか知らないから、実はIntelは軒並み512バイトってこともあるかもしれないけど…
時間出来たらMySQLのベンチマークでも取りたい所だけど、しばらく時間かかりそう。sysbenchなり適当なので取ったら日記に書きたい所。とりあえずしばらくは適当にいじってよう。
別な記事では"1日に全容量を10回書き変えても5年もつ"という話しも書いてあったので、ベンチマークでかなりしばいてもきっと大丈夫。
MySQL5.6のmysqlbinlogコマンド
MySQL5.6からmysqlbinlogコマンドにバイナリログをバックアップするためのオプションが多数追加されています。その中からめぼしいオプションについてまとめます。なお、一度は公式ドキュメントを読む事をお勧めします。
基本的にオプションは省略形で記載していません。適宜()で省略形を記載しています。
リモートのMySQLのバイナリログをコピー
オプションにより色々なコピーの仕方が用意されています。基本的には--read-from-remote-serverオプション(-R)をベースとして用途により追加でオプションを指定します。
接続されるMySQLから見るとSlaveからの接続と変わらないようなのでserver_idをオプションで指定可能な物もあります。指定しない場合は使用するオプションにより0、または65535がデフォルトで使用されます。条件については以下のようになります。
- --read-from-remote-serverのみの場合
- server_idとして0がデフォルトで使用されます。終了し次第接続が切られるためです。
- --read-from-remote-server と --stop-neverの両方の場合
- server_idとして65535がデフォルトで使用されます。--stop-never-slave-server-idオプション(省略形無し)でserver_idを指定可能です。
今回使用しているユーザの権限は REPLICATION SLAVE, REPLICATION CLIENTの2つのみで、レプリケーション用ユーザと同じ権限で確認しています。
指定したバイナリログのコピー
# mysqlbinlog -urepl -p --read-from-remote-server --host=192.168.1.237 --raw mysql-bin.000001 Enter password: # # ls -l total 4 -rw-rw-r-- 1 root root 1698 Nov 14 02:40 mysql-bin.000001 #
この場合、実行したカレントディレクトリにmysql-bin.000001という同一ファイル名で保存されます。また、以下のように複数ファイルを指定する事でまとめてコピーが可能です。
# /usr/local/mysql/bin/mysqlbinlog -urepl -p --read-from-remote-server --host=192.168.1.237 \
--raw mysql-bin.000001 mysql-bin.000002
Enter password:
# ls -l
total 8
-rw-rw-r-- 1 root root 1698 Nov 14 02:42 mysql-bin.000001
-rw-rw-r-- 1 root root 470 Nov 14 02:42 mysql-bin.000002
#なお、--rawオプション(省略形無し)を指定しない場合は mysqlbinlog ./mysql-bin.000001 を実行した場合と同様、テキストとして標準出力されます。
# mysqlbinlog -urepl -p --read-from-remote-server --host=192.168.1.237 mysql-bin.000002 Enter password: /*!40019 SET @@session.max_insert_delayed_threads=0*/; /*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/; DELIMITER /*!*/; # at 4 #121114 2:35:55 server id 237 end_log_pos 120 CRC32 0xc99a96dd Start: binlog v 4, server v 5.6.8-rc-log created 121114 2:35:55 BINLOG ' +4SiUA/tAAAAdAAAAHgAAAAAAAQANS42LjgtcmMtbG9nAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXAAEGggAAAAICAgCAAAACgoKGRkAAd2W msk= '/*!*/; # at 120 #121114 2:35:55 server id 237 end_log_pos 191 CRC32 0xa67e4728 Previous-GTIDs # C4F64A91-2A2B-11E2-9084-5254003E1CEC:1-6 # at 191 #121114 2:36:02 server id 237 end_log_pos 239 CRC32 0x97ca0ec0 GTID [commit=yes] SET @@SESSION.GTID_NEXT= 'C4F64A91-2A2B-11E2-9084-5254003E1CEC:7'/*!*/; # at 239 #121114 2:36:02 server id 237 end_log_pos 326 CRC32 0xce3aa2a0 Query thread_id=19 exec_time=0 error_code=0 SET TIMESTAMP=1352828162/*!*/; SET @@session.pseudo_thread_id=19/*!*/; SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/; SET @@session.sql_mode=1075838976/*!*/; SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/; /*!\C utf8 *//*!*/; SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/; SET @@session.time_zone='SYSTEM'/*!*/; SET @@session.lc_time_names=0/*!*/; SET @@session.collation_database=DEFAULT/*!*/; BEGIN /*!*/; # at 326 #121114 2:36:02 server id 237 end_log_pos 439 CRC32 0x3b6fbcf9 Query thread_id=19 exec_time=0 error_code=0 use `test`/*!*/; SET TIMESTAMP=1352828162/*!*/; insert into test values (NOW()) /*!*/; # at 439 #121114 2:36:02 server id 237 end_log_pos 470 CRC32 0x32ddc489 Xid = 217 COMMIT/*!*/; DELIMITER ; # End of log file ROLLBACK /* added by mysqlbinlog */; /*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/; #
コピーするバイナリログがコピー元サーバから削除されている場合(expire_logs_daysやpurge master logs to等で)はエラーとなります。
ERROR: Got error reading packet from server: Could not find first log file name in binary log index file
指定したバイナリログ以降を全てコピーする
--to-last-logオプション(-t)を使用すると指定したバイナリログ以降を全てコピーする事が出来ます。
# mysqlbinlog -urepl -p --read-from-remote-server --host=192.168.1.237 \
--raw --to-last-log mysql-bin.000004
Enter password:
# ls -l
total 16
-rw-rw-r-- 1 root root 517 Nov 14 02:51 mysql-bin.000004
-rw-rw-r-- 1 root root 796 Nov 14 02:51 mysql-bin.000005
-rw-rw-r-- 1 root root 517 Nov 14 02:51 mysql-bin.000006
-rw-rw-r-- 1 root root 470 Nov 14 02:51 mysql-bin.000007
#
指定したバイナリログ以降を停止するまでコピーし続ける
--stop-neverオプション(省略形無し)を使用することでctrl+c等で停止するまで追加されるバイナリログをコピーし続ける事が出来ます。
実行前のコピー元のMySQLの状態
mysql> show master logs; +------------------+-----------+ | Log_name | File_size | +------------------+-----------+ | mysql-bin.000001 | 1698 | | mysql-bin.000002 | 517 | | mysql-bin.000003 | 796 | | mysql-bin.000004 | 517 | | mysql-bin.000005 | 796 | | mysql-bin.000006 | 517 | | mysql-bin.000007 | 470 | +------------------+-----------+ 7 rows in set (0.00 sec) mysql>
--stop-neverを使用してバイナリログをコピー
# mysqlbinlog -urepl -p --read-from-remote-server --host=192.168.1.237 --raw --stop-never mysql-bin.000001 Enter password:
コピーしたバイナリログを確認
# ls -l total 28 -rw-rw-r-- 1 root root 1698 Nov 14 03:03 mysql-bin.000001 -rw-rw-r-- 1 root root 517 Nov 14 03:03 mysql-bin.000002 -rw-rw-r-- 1 root root 796 Nov 14 03:03 mysql-bin.000003 -rw-rw-r-- 1 root root 517 Nov 14 03:03 mysql-bin.000004 -rw-rw-r-- 1 root root 796 Nov 14 03:03 mysql-bin.000005 -rw-rw-r-- 1 root root 517 Nov 14 03:03 mysql-bin.000006 -rw-rw-r-- 1 root root 439 Nov 14 03:03 mysql-bin.000007 #
コピー元のMySQLでflush binary logsを実行
mysql> flush binary logs; Query OK, 0 rows affected (0.03 sec) mysql> show master logs; +------------------+-----------+ | Log_name | File_size | +------------------+-----------+ | mysql-bin.000001 | 1698 | | mysql-bin.000002 | 517 | | mysql-bin.000003 | 796 | | mysql-bin.000004 | 517 | | mysql-bin.000005 | 796 | | mysql-bin.000006 | 517 | | mysql-bin.000007 | 517 | | mysql-bin.000008 | 191 | +------------------+-----------+ 8 rows in set (0.00 sec) mysql>
コピー先でmysql-bin.000008がコピーされている事を確認
# ls -l total 32 -rw-rw-r-- 1 root root 1698 Nov 14 03:03 mysql-bin.000001 -rw-rw-r-- 1 root root 517 Nov 14 03:03 mysql-bin.000002 -rw-rw-r-- 1 root root 796 Nov 14 03:03 mysql-bin.000003 -rw-rw-r-- 1 root root 517 Nov 14 03:03 mysql-bin.000004 -rw-rw-r-- 1 root root 796 Nov 14 03:03 mysql-bin.000005 -rw-rw-r-- 1 root root 517 Nov 14 03:03 mysql-bin.000006 -rw-rw-r-- 1 root root 517 Nov 14 03:03 mysql-bin.000007 -rw-rw-r-- 1 root root 120 Nov 14 03:03 mysql-bin.000008 #
上記のような振る舞いとなりますので--rawオプションを使用しない場合、垂れ流し状態に出来ます。
また、従来通りに開始ポジションを指定可能ですので例えばmysqldumpコマンドで --single-transaction --master-data=2オプションを使用してダンプを取得した場合、ロールフォワードリカバリ用に以下のように必要なバイナリログをコピーする事も可能です。
ダンプファイルには以下のように記載されていたとします。
-- CHANGE MASTER TO MASTER_LOG_FILE='mysql-bin.000008', MASTER_LOG_POS=749;
指定したポジションからコピーする。
# mysqlbinlog -urepl -p --read-from-remote-server --host=192.168.1.237 \
--stop-never --raw --start-position=749 mysql-bin.000008公式ドキュメントにも記載されていますが、以下のようにすることでリストア後のMySQLに直接バイナリログを流し込む事が可能です。
# mysqlbinlog -urepl -p --read-from-remote-server --host=192.168.1.237 \
--start-position=749 mysql-bin.000008 mysql-bin.000009 | mysql --host=host_name -u root -p
その他オプション
これまでに記載したオプションで基本的な事は可能かと思いますが、以下のようにちょっと便利なオプションがあります。
保存するバイナリログにプリフィックスを付与する
--result-fileオプション(-r)を使用する事でプリフィックスを付与出来ます。コピー元となるサーバの情報を付けるのがおそらく一般的かと。
# mysqlbinlog -urepl -p --read-from-remote-server --host=192.168.1.237 \
--to-last-log --raw --result-file=DBM- mysql-bin.000001
Enter password:
# ls -l
total 32
-rw-rw-r-- 1 root root 1698 Nov 14 03:33 DBM-mysql-bin.000001
-rw-rw-r-- 1 root root 517 Nov 14 03:33 DBM-mysql-bin.000002
-rw-rw-r-- 1 root root 796 Nov 14 03:33 DBM-mysql-bin.000003
-rw-rw-r-- 1 root root 517 Nov 14 03:33 DBM-mysql-bin.000004
-rw-rw-r-- 1 root root 796 Nov 14 03:33 DBM-mysql-bin.000005
-rw-rw-r-- 1 root root 517 Nov 14 03:33 DBM-mysql-bin.000006
-rw-rw-r-- 1 root root 517 Nov 14 03:33 DBM-mysql-bin.000007
-rw-rw-r-- 1 root root 749 Nov 14 03:33 DBM-mysql-bin.000008
#
binlog_checksumによるチェックを有効にする
--verify-binlog-checksumオプション(-c)を使用する事で可能なようです。解説が少なくて合ってるか若干怪しいですがbinlog_checksumオプション(デフォルトCRC32)にてチェックするものと考えられます。
.mylogin.cnfを使用してログイン情報を省略
mysql_config_editorコマンドで予め所定の.mylogin.cnfを作成しておくことにより、--login-pathオプション(省略形無し)を使う事でログイン情報を省略する事が可能です。
以下のようにdbmというlogin-pathで作成します。
# mysql_config_editor set --login-path=dbm --host=192.168.1.237 --user=repl --password Enter password: #
実行後、rootの場合は/root/.mylogin.cnfファイルが作成されます。作成した内容は以下のように確認可能です。
# mysql_config_editor print --all [dbm] user = repl password = ***** host = 192.168.1.237 #
--login-pathを使用した場合は以下のようになります。
# mysqlbinlog --login-path=dbm --read-from-remote-server \
--to-last-log --raw --start-position=749 mysql-bin.000008
# ls -l
total 12
-rw-rw-r-- 1 root root 167 Nov 14 04:08 mysql-bin.000008
-rw-rw-r-- 1 root root 517 Nov 14 04:08 mysql-bin.000009
-rw-rw-r-- 1 root root 470 Nov 14 04:08 mysql-bin.000010
# このようにだいぶすっきりします。ユーザ情報・パスワードを入力する必要がないのでより楽ですし、自動実行のためにパスワードを平文で保存する必要もないためmysql_config_editorコマンドが存在しなかったころよりもセキュアにすることが出来ます。
まとめ
MySQL5.6からはgtidが追加されたこともあり、バイナリログのバックアップは以前のバージョンよりは必要性が上がったと思いますのでmysqlbinlogコマンドによるバックアップはそこそこ使われるのではないかと思います。
これまででもバイナリログのバックアップを希望される所は実際にあったため、その作業が結構楽になると思います。rsyncなりscpなりのシェルスクリプトを書かなくて良いだけでもどんだけ楽か…
個人的にはrsyncコマンドの--bwlimit的なオプションがあったら良いのになぁと。一気にコピー元に対して読み取り負荷がかかるのはサービス中だとちょっと… となりますので。
gtidに絡みそうなオプションも見受けられたため、何かしら重要そうな点があったら何かしらまた書くと思います。
