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なりが到達していれば処理は行われるだろうなぁ、と推測。

まとめ

サイズの大きいファイルのダウンロード中だと499は記録されなかったため、以下のような時に記録されると考えられます。

  • nginx <-> Apache(proxy先)間での処理中、かつクライアントにデータを送信する前にクライアントから切断された場合

本当はソースコードの中までしっかり確認した方が良いんだけど、最近忙しくてそこまで手を出せず… ざっくりとしか確認してないので興味のある方は{ソース展開dir}/src/http/ngx_http_upstream.c当たりを見ると良いと思います。

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に出来ると思います。こちらはまだ実際に試した事無いです。

終わりに

MySQL5.5だとこんな感じでtcmallocを使用するように出来ます。以前通常コンパイルMySQLと後述のcmake時点で組み込む形でtcmallocを使用するようにしたMySQL、両方5.5系、ではベンチマーク(sysbench)を行った際にtcmallocの方が同時接続数が増えた際の性能の落ち込みが少なかったです。またほとんどのケースでtcmallocの方がtransaction/secは高い値となりました。
先日の日記で書いたSSDベンチマークを取る際もtcmallocの使用有無でどの程度差が出るか検証してみたいと思います。

IntelのDC S3700 200GB買ってみた

気付いたらだいぶ長い事何も書いてなかったなぁ。とりあえずネタになりそうなSSDIntelの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に絡みそうなオプションも見受けられたため、何かしら重要そうな点があったら何かしらまた書くと思います。

mysqlfailoverの--exec-beforeと--exec-after

mysqlfailoverコマンドの--exec-beforeと--exec-afterオプションについて。なお、動作確認したのは--exec-afterの場合のみです。
mysqlfailoverで--helpを実行すると以下のように表示されます。

--exec-after=EXEC_AFTER
                      name of script to execute after failover or switchover
--exec-before=EXEC_BEFORE
                      name of script to execute before failover or
                      switchover

説明にある通りfailover/switchover前後に動作するスクリプトを指定出来ます。とりあえずシェルスクリプトで書いて動かしたけど動作したので実行権等が適切に設定されていれば言語は問わなそうです。スクリプトの返り値が0なら正常終了、それ以外は異常終了と見なすのでそこだけ気をつければ大丈夫そう。

failoverが発生した際に動作するのはtopology.pyにあるdef failoverの中。--exec-beforeが1515行目、--exec-afterが1537行目。switchoverの場合はdef switchoverの中を参照して下さい。

1503         # Prepare candidate
1504         self._report("# Preparing candidate for failover.")
1505         self._prepare_candidate_for_failover(new_master, user, passwd)
1506 
1507         # Create replication user on candidate.
1508         self._report("# Creating replication user if it does not exist.")
1509 
1510         # Need Master class instance to check master and replication user
1511         self.master = self._change_role(new_master, False)
1512         res = self.master.create_rpl_user(host, port, user, passwd)
1513 
1514         # Call exec_before script - display output if verbose on
1515         self.run_script(self.before_script, False)
1516 
1517         # Stop all slaves
1518         self._report("# Stopping slaves.")
1519         self.run_cmd_on_slaves("stop", not self.verbose)
1520 
1521         self._report("# Switching slaves to new master.")
1522         for slave_dict in self.slaves:
1523             slave = slave_dict['instance']
1524             # skip dead or zombie slaves
1525             if slave is None or not slave.is_alive():
1526                 continue
1527             slave.switch_master(self.master, user, passwd, False, None, None,
1528                                 self.verbose and not self.quiet)
1529 
1530         # Take the server out of the list.
1531         self._remove_slave(new_master_dict)
1532 
1533         # Starting all slaves
1534         self._report("# Starting slaves.")
1535         self.run_cmd_on_slaves("start", not self.verbose)
1536 
1537         # Call exec_after script - display output if verbose on
1538         self.run_script(self.after_script, False)
1539 
1540         # Check slaves for errors

なお、run_scriptもtopology.pyで定義されています。

 506     def run_script(self, script, quiet):
 507         """Run an external script
 508         
 509         This method executes an external script. Result is checked for
 510         success (res == 0).
 511         
 512         script[in]     script to execute
 513         quiet[in]      if True, do not print messages
 514         
 515         Returns bool - True = success
 516         """
 517         from mysql.utilities.common.tools import execute_script
 518 
 519         if script is None:
 520             return
 521         self._report("# Spawning external script.")
 522         res = execute_script(script)
 523         if res == 0:
 524             self._report("# Script completed Ok.")
 525         elif not quiet:
 526             self._report("ERROR: %s Script failed. Result = %s" %
 527                          (script, res), logging.ERROR)

mysqlfailoverが動作した際にMasterが変更されたSlaveでは未だにSQL_THREADが停止した状態になるのでシェルスクリプトを--exec-afterに設定し、SQL_THREADが開始されるか確認してみました(SQL_THREADが開始されない原因は未だによく分からず…)。
環境は以前の日記と同様です。実行コマンドとシェルスクリプトは以下のように。

実行コマンド

# /usr/local/mysql-wb/bin/mysqlfailover \
  --master=failover:failover@192.168.1.237 \
  --slaves=failover:failover@192.168.1.238,failover:failover@192.168.1.240  \
  --candidates=failover:failover@192.168.1.238 \
  --log=/tmp/failover.log \
  --exec-after=/root/bin/check_slave.sh 

シェルスクリプト

#!/bin/sh

LOG=/tmp/exec_after.log

while [ ${CHK_CNT:=3} -gt 0 ]; do
   CNT=`/usr/local/mysql-5.6.7-rc/bin/mysql -h 192.168.1.240 -P 3306 -ufailover -pfailover -e 'show slave status\G' | egrep -i 'Slave_IO_Running|Slave_SQL_Running' | grep -i Yes | wc -l`

   if [ $CNT -eq 2 ]; then
      echo 'OK: slave running' >> $LOG
      exit
   else
      echo 'NG: slave not running' >> $LOG 
      /usr/local/mysql-5.6.7-rc/bin/mysql -h 192.168.1.240 -P 3306 -ufailover -pfailover -e 'start slave'
   fi
   sleep 3
   CHK_CNT=`expr $CHK_CNT - 1`
done

実行時の/tmp/failover.log

2012-11-10 03:39:12 AM INFO Master may be down. Waiting for 3 seconds.
2012-11-10 03:39:15 AM INFO Cannot reconnect to master.
2012-11-10 03:39:18 AM CRITICAL Master is confirmed to be down or unreachable.
2012-11-10 03:39:18 AM INFO Failover starting in 'auto' mode...
2012-11-10 03:39:18 AM INFO Candidate slave 192.168.1.238:3306 will become the new master.
2012-11-10 03:39:18 AM INFO Preparing candidate for failover.
2012-11-10 03:40:10 AM INFO Creating replication user if it does not exist.
2012-11-10 03:40:10 AM INFO Stopping slaves.
2012-11-10 03:40:10 AM INFO Performing STOP on all slaves.
2012-11-10 03:40:10 AM INFO Switching slaves to new master.
2012-11-10 03:40:10 AM INFO Starting slaves.
2012-11-10 03:40:10 AM INFO Performing START on all slaves.
2012-11-10 03:41:01 AM INFO Spawning external script.
2012-11-10 03:41:04 AM INFO Script completed Ok.
2012-11-10 03:41:04 AM INFO Checking slaves for errors.
2012-11-10 03:41:04 AM INFO Failover complete.

--exec-afterとかの動作確認用なので色々ザルなスクリプトです。ソース、ログからも分かる通り--exec-afterは切り替え完了後に動作するスクリプトとなります。上記スクリプトは192.168.1.240がSlaveとなっていることを前提として、レプリケーションSQL_THREAD, IO_THREADのどちらか、または両方が停止してたらstart slaveするだけの簡単な処理です。

--candidatesで複数サーバを指定している場合は適切にfailover後のMaster, Slaveを判定する事が必要。ソース見る限りはスクリプトに対して引数とかは渡して無いようなのでdef run_scriptを改造してその辺り判定しやすいようにするのが良さそう。

一応、--exec-afterでstart slaveしたSlaveのMySQLのエラーログ。1回エラーになったのをstart slaveで無理矢理開始。

121110  3:41:01 [ERROR] Error writing relay log configuration.
121110  3:41:01 [ERROR] Slave SQL: Failed during slave workers initialization, Error_code: 1593
121110  3:41:01 [Note] Slave SQL thread initialized, starting replication in log 'FIRST' at position 0, relay log './mysql-relay-bin.000001' position: 4

MasterをDNSで切り替えたりする場合には--exec-afterで実行するスクリプト内で処理させる事になりそう。VIPの遷移もやろうと思えば出来るだろうけど、適切に元Masterのサーバを処理する必要があるのでVIPは個人的にはあまりやりたいと思わない…

実運用で使おうと思うと色々考慮しないといけない点が多いけど上手く使えば便利なのは間違い無いわけで。ざっくり考慮しないといけないことを考えると

  • アプリケーション側からの参照切り替え方法
    • DNS, またはVIP? DNSの場合はDNSキャッシュは大丈夫? VIPの場合は元Masterが勝手に起動して来た場合は大丈夫?
  • 元Master復旧後の切り戻し方法
    • 切り戻さないでSlaveとして追加する等々
  • 上2つに関連して間違って元Masterを更新しちゃったら?
    • read_onlyオプションで回避出来るような適切な権限設定だったら上手く仕込めるか考えるのもありか?

とかぐらい?

仕事ではアプリケーションの面倒は基本的に見ていないので開発されている人から見るとこれも、ってのがあるかもしれません。とはいえ、この手の処理でアプリケーション側で手を加えるのはナンセンスだと思うのでインフラ側の処理だけでどうにかするのが良いんだろうなぁ。
自宅でcode igniter使って適当にPHPいじっていますが、database.phpを書き換えるとか台数多いと考えたくない… いくら自動化しても漏れとか起こりえるからなぁ。

Global Transaction IDを使ってレプリケーション構成とした際の制限

2012/11/08に一部追記しました。

Global Transaction IDを有効にしてレプリケーション構成とした際の制限について簡単にまとめてみる。微妙な訳になっている部分もあるだろうし、勘違いしてる箇所もあるかもしれないのでご注意下さい。

よって、アレ?、というのがありましたら基本的には公式ドキュメントを参照して下さい。
むしろ誤りあったら突っ込んでもらえると助かります。

前提
MySQL5.6 RC版(5.6.7-rc)でgtidを使ったレプリケーション環境で確認

トランザクションが使えないストレージエンジンは使用出来ない(MyISAM等)

前の日記でも書いていますが、以下のようにエラーとなります。

ERROR 1785 (HY000): Updates to non-transactional tables are forbidden when DISABLE_GTID_UNSAFE_STATEMENTS = 1.

MasterとSlaveで同一テーブルで異なるストレージエンジンは使用してはいけない

MasterとSlaveで異なるbinlog_formatは使用してはいけない

ちょっとこの部分は実際に上手く試せなかったのでどうなるかはっきりとしていません。MasterでInnoDB、SlaveでMyISAMの組み合わせだと当然以下のようにSlave側でエラーが起きます。

Last_Errno: 1785
Last_Error: Error 'Updates to non-transactional tables are forbidden when DISABLE_GTID_UNSAFE_STATEMENTS = 1.' on query. Default database: 'test'. Query: 'insert into test values ()'

InnoDB以外のトランザクションが使用可能なストレージエンジンの場合はエラーにならないけどgtidがおかしくなるのかもしれません。

異なるbinlog_formatですがドキュメント通りにMasterでROW、SlaveでSTATEMENTにしたけどエラーは発生せず、ぱっとみ普通に動いているように見えました。クエリの種類にもよるのかな… Slaveではlog_slave_updatesを有効にしているのでshow binlog events in 'mysql-bin.000002'で見た感じではSET @@SESSION.GTID_NEXT= の右辺は同じでした。

上手く行かない状況がよく分からなかったので 使用してはいけない という記述にしました。とはいえ、ドキュメントにあるのだから同じにしておく方が良いでしょう。

CREATE TABLE ... SELECT はサポートされない(使用出来ない)

以下のようにエラーになります。

mysql> create table test_copy ( id int not null auto_increment, primary key(id)) select * from test;
ERROR 1786 (HY000): CREATE TABLE ... SELECT is forbidden when DISABLE_GTID_UNSAFE_STATEMENTS = 1.

以下だいぶ適当な訳。
CREATE TABLE ... SELECTはSTATEMENTベースのレプリケーションだと安全では無い、んじゃROWベースならOKかというとバイナリログのイベントとしては以下の2つに分割されるためそうでもない。

  • 1つはCREATE TABLE
  • もう1つはINSERT

またトランザクション内でCREATE TABLE ... SELECTを実行した場合、上記の2つのイベントが場合によっては同じトランザクションIDとしてSlaveに送られる事があり、その場合、SlaveではINSERTはスキップされることになる。よってCREATE TABLE ... SELECTはサポートされない。

CREATE TEMPORARY TABLE と DROP TEMPORARY TABLEはサポートされない

2012/11/08追記
勘違いしてたようでトランザクション内だとエラーになるようです。

mysql> begin;
Query OK, 0 rows affected (0.00 sec)

mysql> create temporary table test (id int not null, primary key(id) ) ENGINE=InnoDB;
ERROR 1787 (HY000): When DISABLE_GTID_UNSAFE_STATEMENTS = 1, the statements CREATE TEMPORARY TABLE and DROP TEMPORARY TABLE can be executed in a non-transactional context only, and require that AUTOCOMMIT = 1.
mysql> 

まぁ、なんにしろオプション名とか変わるみたいなので、正式版リリースされたら再度確認かな…
追記ここまで

5.6.7-rcだと動いちゃうようですが、バグのようなので新しいバージョンが出たら再度試したいと思います(参考リンク)
以下リンク先の記載抜粋。

Prior to MySQL 5.6.9, this option was named --disable-gtid-unsafe-statements. (Bug #14775984)

Prior to MySQL 5.6.7, using this option caused nontransactional DML on temporary tables to fail, although 
changes to temporary tables are not logged when using row-based binary logging. In MySQL 5.6.7 and later, 
nontransactional DML statements are allowed on temporary tables with --disable-gtid-unsafe-statements 
(--enforce-gtid-consistency beginning with MySQL 5.6.9) as long as all affected tables are temporary tables (Bug #14272672).

gtidが有効な場合のmysqldump

5.6.10からmysqldumpからスレーブを作成可能だったので訂正しています。gtidを使用した環境でのmysqldump
ダンプの取得は可能です。ただ、--all-databasesのように全てのデータベースを対象とした場合ダンプファイルにはmysql.userのようなトランザクションをサポートしないテーブルのデータも含まれるためgtid-mode=ONな場合はリストア時にエラーになります。もちろん、対象としてInnoDBしか存在しないデータベースを指定してダンプした場合はリストアでもエラーになりません。

ただ、mysqldumpを使ったダンプファイルを使用して新規にgtidを使用したSlaveを追加出来るかというと出来ません。mysqldumpではgtidを記録してくれないためです。
gtid-mode=ONなサーバにリストアを行うと新規にgtidを割り当ててしまい、CHANGE MASTER TOでMASTER_AUTO_POSITION=1としてもエラーが発生します。
よってgtidも含めてリストアをしたいのであればバイナリログとmysqlbinlogコマンドを使用する必要があります。

とまぁ、こんな感じだと思うんだけど非常に微妙。mysqldumpでリストアした後、後続のイベントを2、3個、mysqlbinlog使って読み込ませた上でstart slaveしたけどエラーになりました。なんか上手いやり方ないのかと模索中です。正直バイナリログを全部取っておくのはしんどい。
お金あるところであれば遅延レプリケーション使ってバックアップ用のサーバ用意しておくとかでMySQL停止、datadirをまるっとコピー、とかで直せそうだけど、そんなところ多くないし。gtid使わなければ良いと言われればその通り。今の所mysqlfailoverを使う場合やレプリケーション設定時にMASTER_LOG_FILE, MASTER_LOG_POSを指定しなくて良いという以外の使いどころが分かってないので使いどころ見極めないと面倒くさい事になりそう。

gtidが有効な場合のmysql_upgradeコマンド

5.6.7以降は--write-binlog=OFFがデフォルトなので特別意識しなくて大丈夫ですが、レプリケーション構成の場合はMaster, Slaveそれぞれで実行する必要があります。
5.6.7より前は--write-binlog=ONのため、MyISAM型テーブルへの更新が入るためエラーとなっていたようです。