b.l0g.jp     About     Archive     Feed

MySQLエラーログに出てきたエラーコードのとっかかり

MySQLのエラーログに記録されるエラーコードは、MySQL自体が判断して表示するものと、OSが返したエラーコードをMySQLが表示しているものとの2種類に分けられる。それぞれまずどう調べ始めるか、という話。MySQL Performance Blogのエントリに、後で自分の役に立つように情報を加えてみた。

例えば、レプリケーションがうまくいかない時に表示される

  
Got fatal error 1236 from master when reading data from binary log: 'Client requested master to start replication from impossible position'
  

というエラーの「1236」は、MySQL自体が判断した結果なので、以下のサイトで一覧が見られる。というか、表示されているままで、それ以上の情報はエラーログの前後や他のログ(OSログなど)を確認するしかない。

4.1

MySQL 4.1 リファレンスマニュアル 12.1. 返されるエラー

5.0/5.1/5.5 (バージョン部分を変えるだけで全部URLは同じ)

MySQL 5.0 Reference Manual C.3. Server Error Codes and Messages

MySQL 5.0 Reference Manual C.4. Client Error Codes and Messages

一方、以下のようなエラーの場合、

  
120326 16:56:45 [ERROR] /usr/sbin/mysqld: Incorrect key file for table '/tmp/#sql\_21b2\_0.MYI'; try to repair it
  
120326 16:56:45 [ERROR] Got an error from unknown thread, storage/myisam/mi_write.c:223
  
120326 16:56:45 [ERROR] /usr/sbin/mysqld: Sort aborted: Error writing file '/tmp/MYK74Kpi' (Errcode: 28)
  

エラーコードを調べないままだと、ファイルへの書き出しで失敗したことまでは分かっても、その先何が起きているのかは分からない。ここで、「Errcode: 28」は、OSが返しているエラーを表示している。これがどのような意味かは、perrorコマンドで分かる。

  
$ perror 28
  
OS error code 28: No space left on device
  

エラーログだけでは判断がつかないが、エラーコード28の意味が分かると、単純な問題であることが判明する。MyISAMはディスクがいっぱいであるというエラーを正しく扱わないという問題があるので、このようなことになる。

perrorコマンド、MySQLに付属している小ネタ的コマンドだが、OSエラーコードをそのまま表示する他のソフトウェアのエラーログを見る時にも役立ちそうだ。

MySQL 5.6.5の新機能GTIDを試してみる

4月10日にリリースされたMySQL 5.6.5 DMRに、GTID(Global Transaction ID)という機能が搭載された。これは、トランザクションにID(GTID)を持たせることによって、レプリケーションの進行具合を、従来の「マスタのbinlogファイル名 + ポジション」という情報ではなく、GTIDで管理できるようになるという機能である。従来のバージョンと比べた時に一番分かりやすい点としては、「change masterする時にポジションを指定しなくてよくなる」ということだろう。

MySQLのレプリケーション機能開発者Luis Soares氏のブログを参考に、GTIDの機能を試してみた。

MySQL 5.6.5のインストール

MySQLのダウンロードサイトからDevelopment Releaseを選択し、5.6.5 m8をダウンロードする。自分はUbuntu 11.04を使ったので、debファイルをダウンロードし、以下のコマンドを実行したところ、/opt/mysql以下にインストールされた。

  
dpkg -i mysql-5.6.5-m8-ubuntu10.04-x86_64.deb
  

ちなみに自分はマシンを2台用意できなかったので、/opt/mysql以下をコピーしてからmysql_install_dbコマンドを実行し、それぞれmy.cnfを作成して、1台の検証用サーバにポートを分けて2つのMySQLを起動した。

GTIDを使うのに必要な設定

GTIDを使用するには、レプリケーションを組むサーバ全体でGTIDを有効にする必要があり、それぞれのサーバのmy.cnfで以下のオプションを指定する。

  
log-bin
  
log-slave-updates
  
gtid-mode=ON
  
disable-gtid-unsafe-statements
  

はじめの2つはレプリケーションを設定したことのある人なら見慣れたオプションだが、後半の2つが新しく追加されたもの。gtid-modeは単純にGTIDの機能を使用可能にするオプションで、disable-gtid-unsafe-statementsは、GTIDと互換性のない一部のSQLの実行を無効にするものである。

(2013.03.26追記) disable-gtid-unsafe-statementsはMySQL 5.6.9で廃止されたので、5.6.9以降ではenforce-gtid-consistencyを使用すること。

これらの設定を行ってMySQLを起動すると、GTIDが有効になる。

  
mysql> show variables like '%gtid%';
  
+-----------+----+
  
| Variable_name | Value |
  
+-----------+----+
  
| disable\_gtid\_unsafe_statements | ON |
  
| gtid_done | |
  
| gtid_lost | |
  
| gtid_mode | ON |
  
| gtid_next | AUTOMATIC |
  
| gtid_owned | |
  
+-----------+----+
  
6 rows in set (0.00 sec)
  

レプリケーションの設定

GTIDを設定するとトランザクションごとにGTIDを持つと書いたが、まず簡単なcreate文を書いてみる。その後show binlog eventsでbinlogの中身を見てみると、クエリの情報の他にGTIDがセットされていることが分かる。

  
mysql-master> use test;
  
Database changed
  
mysql-master> create table t1 (a INT);
  
Query OK, 0 rows affected (0.13 sec)

mysql-master> show binlog events;
  
+------+--+------+----+-----+-----------------------+
  
| Log\_name | Pos | Event\_type | Server\_id | End\_log_pos | Info |
  
+------+--+------+----+-----+-----------------------+
  
| mysql-bin.000001 | 4 | Format_desc | 1 | 120 | Server ver: 5.6.5-m8-log, Binlog ver: 4 |
  
| mysql-bin.000001 | 120 | Previous_gtids | 1 | 147 | |
  
| mysql-bin.000001 | 147 | Gtid | 1 | 191 | SET @@SESSION.GTID_NEXT= '7C3125E9-8C6D-11E1-8BE6-2C4138876DB7:1' |
  
| mysql-bin.000001 | 191 | Query | 1 | 284 | use \`test\`; create table t1 (a INT) |
  
+------+--+------+----+-----+-----------------------+
  
4 rows in set (0.00 sec)
  

この例で表示されている、’7C3125E9-8C6D-11E1-8BE6-2C4138876DB7:1’が、直後のcreate tableに割り当てられたGTIDである。さらにinsert文を発行してみる。

  
mysql-master> insert into t1 values (1);
  
Query OK, 1 row affected (0.13 sec)

mysql-master> show binlog events;
  
+------+--+------+----+-----+-----------------------+
  
| Log\_name | Pos | Event\_type | Server\_id | End\_log_pos | Info |
  
+------+--+------+----+-----+-----------------------+
  
| mysql-bin.000001 | 4 | Format_desc | 1 | 120 | Server ver: 5.6.5-m8-log, Binlog ver: 4 |
  
| mysql-bin.000001 | 120 | Previous_gtids | 1 | 147 | |
  
| mysql-bin.000001 | 147 | Gtid | 1 | 191 | SET @@SESSION.GTID_NEXT= '7C3125E9-8C6D-11E1-8BE6-2C4138876DB7:1' |
  
| mysql-bin.000001 | 191 | Query | 1 | 284 | use \`test\`; create table t1 (a INT) |
  
| mysql-bin.000001 | 284 | Gtid | 1 | 328 | SET @@SESSION.GTID_NEXT= '7C3125E9-8C6D-11E1-8BE6-2C4138876DB7:2' |
  
| mysql-bin.000001 | 328 | Query | 1 | 403 | BEGIN |
  
| mysql-bin.000001 | 403 | Query | 1 | 498 | use \`test\`; insert into t1 values (1) |
  
| mysql-bin.000001 | 498 | Xid | 1 | 525 | COMMIT /\* xid=10 \*/ |
  
+------+--+------+----+-----+-----------------------+
  
8 rows in set (0.00 sec)
  

insert文には、’7C3125E9-8C6D-11E1-8BE6-2C4138876DB7:2’というGUIDが振られたことが見て取れる。GUIDは、コロンの前のサーバのUUID(server_uuid変数)と、コロンの後の単純なトランザクションの通し番号からなっているのである。

この時点で、マスタ上には1行だけ値を持つテーブルt1があり、スレーブ側には何も入っていない状態になっているはず。これまでのMySQLの場合スレーブサーバを作るには、

  • マスタを停止してファイルを取るかダンプしてデータをスレーブにコピー
  • スレーブで、マスタの停止あるいはダンプ時点のbinlogファイル名とポジションを指定してchange master
  • start slaveしてレプリケーションを開始し、マスタとスレーブの一致を確認

という手順が必要だった。一方5.6.5では、以下の文をスレーブで実行するだけで、マスタと同じ状態までレプリケーションが行われる。

  
mysql-slave> change master to
    
master_host = 'マスタのIP',
    
master_port=マスタのMySQLポート番号,
    
master_user='レプリ用ユーザ',
    
master_password='レプリ用ユーザパスワード',
    
master\_auto\_position=1;
  
mysql-slave> start slave;
  

最後のmaster_auto_positionによって、GTIDを使って自動的にポジションが決まるので、ポジションを指定する必要がない。レプリケーションを始めた状態でshow slave status\Gを実行すると、手元の環境では以下のようになった(長いので一部の行を省略)。

  
mysql-slave> show slave status\G
  
\***\***\***\***\***\***\***\***\*\\*\* 1. row \*\*\***\***\***\***\***\***\***\****
           
Slave\_IO\_State: Waiting for master to send event
              
Master_Host: 127.0.0.1
              
Master_User: root
              
Master_Port: 3306
            
Connect_Retry: 60
          
Master\_Log\_File: mysql-bin.000001
      
Read\_Master\_Log_Pos: 525
           
Relay\_Log\_File: ubuntu-relay-bin.000002
            
Relay\_Log\_Pos: 727
    
Relay\_Master\_Log_File: mysql-bin.000001
      
Exec\_Master\_Log_Pos: 525
          
Relay\_Log\_Space: 924
    
Seconds\_Behind\_Master: 0
         
Master\_Server\_Id: 1
              
Master_UUID: 7c3125e9-8c6d-11e1-8be6-2c4138876db7
         
Master\_Info\_File: /opt/mysql3307/server-5.6/data/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
       
Retrieved\_Gtid\_Set: 7C3125E9-8C6D-11E1-8BE6-2C4138876DB7:1-2
        
Executed\_Gtid\_Set: 7C3125E9-8C6D-11E1-8BE6-2C4138876DB7:1-2
  
1 row in set (0.00 sec)
  

最後の2行、Retrieved_Gtid_Setはマスタから転送してきたトランザクションのGTIDで、Executed_Gtid_Setはスレーブで実行されたトランザクションのGTIDである。ここでスレーブ側のbinlogの中身を見てみると、マスタで実行された文がそのまま実行されており、マスタのGTIDも保持されていることが分かる。

  
mysql-slave> show binlog events;
  
+------+--+------+----+-----+-----------------------+
  
| Log\_name | Pos | Event\_type | Server\_id | End\_log_pos | Info |
  
+------+--+------+----+-----+-----------------------+
  
| mysql-bin.000001 | 4 | Format_desc | 13307 | 120 | Server ver: 5.6.5-m8-log, Binlog ver: 4 |
  
| mysql-bin.000001 | 120 | Previous_gtids | 13307 | 147 | |
  
| mysql-bin.000001 | 147 | Gtid | 1 | 191 | SET @@SESSION.GTID_NEXT= '7C3125E9-8C6D-11E1-8BE6-2C4138876DB7:1' |
  
| mysql-bin.000001 | 191 | Query | 1 | 284 | use \`test\`; create table t1 (a INT) |
  
| mysql-bin.000001 | 284 | Gtid | 1 | 328 | SET @@SESSION.GTID_NEXT= '7C3125E9-8C6D-11E1-8BE6-2C4138876DB7:2' |
  
| mysql-bin.000001 | 328 | Query | 1 | 403 | BEGIN |
  
| mysql-bin.000001 | 403 | Query | 1 | 498 | use \`test\`; insert into t1 values (1) |
  
| mysql-bin.000001 | 498 | Xid | 1 | 525 | COMMIT /\* xid=18 \*/ |
  
+------+--+------+----+-----+-----------------------+
  
8 rows in set (0.00 sec)
  

なお、以下のselect文で、最後に実行された文のGTIDが参照できる。この結果がマスタとスレーブで一致していれば、データは同一であるということになる。

  
mysql-master> SELECT @@GLOBAL.GTID_DONE;
  
+--------------+
  
| @@GLOBAL.GTID_DONE |
  
+--------------+
  
| 7C3125E9-8C6D-11E1-8BE6-2C4138876DB7:1-2 |
  
+--------------+
  
1 row in set (0.00 sec)
  

ここまでで確認できたのは、基本的なGTIDの機能だけだが、この他にも自動フェイルオーバーが可能なmysqlfailoverや、レプリケーションの状態を詳細に確認できるmysqlrpladminなど、興味深いツールもあるので、試してみたい。5.6ではレプリケーション関連の色々な機能追加があるので、これからも便利な機能が出てくるのではと楽しみである。

TCP/IPの送信用ポート範囲を変更する

Linuxで、TCP/IPの送信時に使用するポートの範囲を決めるのは、net.ipv4.ip_local_port_range というカーネルパラメータ。手元のCentOSでは以下がデフォルト値になっていた。

  
\# sysctl net.ipv4.ip\_local\_port_range
  
net.ipv4.ip\_local\_port_range = 32768 61000
  

これだと、32768 から 61000 までの 28232 個の中からランダムに選ばれたポートを使って、サーバ側にアクセスする。このポートが足りなくなった場合、/etc/sysctl.conf に設定を書き込んでOSを再起動することで、範囲を変えられる。

  
\# /etc/sysctl.conf に以下を追記
  
net.ipv4.ip\_local\_port_range = 1024 65000
  

再起動

  
\# sysctl net.ipv4.ip\_local\_port_range
  
net.ipv4.ip\_local\_port_range = 1024 65000
  

これで1024から65000までのポートを使用できるようになる。