猫型iPS細胞研究所

Windows、Linux、iOS、DB、Network

DataBase MySQL

MySQLのバイナリログを見てスレーブ停止の原因を調査する

投稿日:2013年1月18日 更新日:

以前スレーブ側の更新がとまっていることに気付きました :x001:
その時のトラブルシューティングの手順です。

1.スレーブ側で、SlaveS tatusを確認する

まずはスレーブの状態を確認し、何が停止しているかをチェックしました。

mysql> show slave status\G
*************************** 1. row ***************************
             Slave_IO_State: Waiting for master to send event
                Master_Host: 192.168.xxx.xxx
                Master_User: xxx
                Master_Port: xxx
              Connect_Retry: 60
            Master_Log_File: mysql-bin.000009         ←①スレーブのI/Oスレッドが現在処理中のマスタのバイナリログファイル名。
        Read_Master_Log_Pos: 242153177                ←①スレーブのI/Oスレッドが読み込んだマスタのバイナリログの位置。
             Relay_Log_File: mysqld-relay-bin.002512  ←②スレーブのSQLスレッドが現在処理中のスレーブのリレーログファイル名。(※重要)
              Relay_Log_Pos: 18199795                 ←②スレーブのSQLスレッドが実行完了したスレーブのリレーログの位置(※重要)
      Relay_Master_Log_File: mysql-bin.000009         ←③スレーブのSQLスレッドが最後に実行したクエリが記録されていたマスタのバイナリログファイル名。
           Slave_IO_Running: Yes
          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: 221243106                ←③スレーブのSQLスレッドが最後に実行したクエリの、マスタのバイナリログでの位置。
            Relay_Log_Space: 39111006
            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
1 row in set (0.00 sec)

①~③は対応している項目を同じ番号にしただけす
『Slave_SQL_Running: No』なので、SQLスレッドが停止していることがわかります。
スレーブへのSQLのインサートエラーのようです。
何故か『Last_Errno: 0』なので原因はよくわかりません。

mysql> stop slave
mysql> start slave

をしてみましたが、やはりSQLスレッドは実行されませんでした。

この後バイナリログを確認するためにはリレーログファイル名とリレーログファイルの位置は重要です。
ここで押さえておきましょう。

2.スレーブ側のログを確認してみる

#cat /var/log/ mysqld.log
120803 10:19:24 [Note] Slave I/O thread: connected to master 'xxx@192.168.xxx.xxx:3306',  replication started in log 'mysql-bin.000009' at position 237373898
120803 10:24:50 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.000009' at position 221243106, relay log '/var/run/mysqld/mysqld-relay-bin.002512' position: 18199795
120803 10:24:50 [Note] Slave SQL thread exiting, replication stopped in log 'mysql-bin.000009' at position 221243106
120803 12:02:31 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.000009' at position 221243106, relay log '/var/run/mysqld/mysqld-relay-bin.002512' position: 18199795

確かにSQLスレッドが停止しているのは確認できたが、やはり原因は不明です。
ちなみにここで表示されている’mysql-bin.000009′ at position 221243106はマスタにあるバイナリログの位置です。

3.スレーブ側でバイナリログのパスを確認する

これは覚えていらっしゃる方は不要ですよね・・・ :x001:
ファイル名は1のshow slave statusで確認できますが、
実際のファイルのパスはこれで確認できます。

#cat /var/lib/mysql/relay-log.info
/var/run/mysqld/mysqld-relay-bin.002516 ←★バイナリログのパスを確認できる
4985047
mysql-bin.000009
242358710

4.スレーブ側でmysqlbinlogコマンドを使ってバイナリログを確認する

スレーブは、マスターから受信したバイナリログをそのまま実行しているだけです。
バイナリログのどこでエラーが発生したかを確認すると、
どういったコマンド・SQLを発行したときに停止したかを確認できます。
重要なことは、どのバイナリログファイルなのか、どの位置(ポジション)なのかを事前に確認することです。

# mysqlbinlog -u xxx -p /var/run/mysqld/mysqld-relay-bin.002512 --start-position=18199874
Enter password:
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 18199874 ←★atがバイナリログの位置(position)を表している
#120802  3:47:18 server id xxx  end_log_pos 28  Intvar
SET INSERT_ID=55738/*!*/;
# at 18199902
#120802  3:47:18 server id xxx  end_log_pos 1762        Query   thread_id=93510297      exec_time=0     error_code=0
use <DB名>/*!*/; ←★DBの選択
SET TIMESTAMP=1343846838/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=1, @@session.unique_checks=1/*!*/;
SET @@session.sql_mode=2097152/*!*/;
/*!\C latin1 *//*!*/;
SET @@session.character_set_client=8,@@session.collation_connection=8,@@session.collation_server=8/*!*/;
SET @@session.time_zone='SYSTEM'/*!*/;
insert into <SQL文>/*!*/; ←★INSERTが走っている・・・
# at 18201636
#120802  3:47:19 server id xxx  end_log_pos 1790        Intvar
SET INSERT_ID=55588/*!*/;
# at 18201664
#120802  3:47:19 server id xxx  end_log_pos 2738        Query   thread_id=93510297      exec_time=0     error_code=0
SET TIMESTAMP=1343846839/*!*/;
insert into <SQL文> ←★INSERTが走っている・・・
1のshow slave statusコマンドで確認した値を使用しましょう。
※Relay_Log_File: mysqld-relay-bin.002512 がスレーブで使っているバイナリログファイル
※Relay_Log_Pos: 18199795 がスレーブで使っているバイナリログファイルの位置です
ログが大量に出力されてしまう場合は、–stop-position=[位置] をつける

positionで指定するのは、バイナリログのatにある値です。

5.原因を究明する

今回の場合、インサートの後に停止しているようです。
スレーブ側のDBを見るとすでに同じキーの値がありました・・・ :x001:
スレーブ側の該当データを削除して、stop slave, start slaveコマンドを実行すると無事スレーブSQLスレッドも動き出しました。

本来ならばレプリケーション側のmy.cnfにはread_onlyを設定しておくべきでしょう。
スレーブ側での更新系クエリを禁止することで今回のような障害は防ぐことができます。
しかし、私のように十分なハード環境もない場合には、レプリケーション側をテストで利用する必用も多々あります。
しかたありません。

バイナリログを確認する手順のまとめ

結局不要な手順が多かったのでまとめておきます。

①エラーの発生しているバイナリログの位置を確認する
mysql> show slave status\Gを実行して、
Relay_Log_File
Relay_Log_Pos
の位置を確認する
②mysqlbinlogコマンドでバイナリログを確認する
mysqlbinlog /var/run/mysqld/[Relay_Log_File] –start-position=[Relay_Log_Pos]


Gooleアドセンス用336

Gooleアドセンス用336

-DataBase, MySQL

執筆者:

関連記事

mysql

CentOS6.4にMySQL5.6をインストールする

INDEX1 RPMのダウンロード2 tarの解凍3 rpmをyumでインストール4 サービス名が違う?5 mysql_secretにrootの初期パスワードはある6 mysql_secure_ins …

sqlserver

application log ってどこ?

SQLSERVERのメンテナンスプランを使用してバックアップを取得していたのですが、取得できていませんでした。 SQL Serverログには下記メッセージが表示されていました。 BACKUP fail …

select insert

私は以前SQLの順番にinsert selectと呼んでいて、笑われたことがあります。 select insertだ!と当時の上司に言われました。 なるほど、副問い合わせのselectが実行されて、そ …

mysql

MySQLのmysqldumpのエクスポートとインポート

ダンプはバックアップやテストに大活躍してくれます。 しかし、データベース単位でエクスポートしても、インポートには随分時間がかかったりします。 その辺は別の機会にしますが、今回は基本コマンドのまとめです …

sqlserver

SQLSERVER「Login failed for user ‘xxxxxxx’. 理由: 指定された名前に一致するログインが見つかりませんでした」

Windows認証でAdministratorを指定しているのにログインできない。 そんな場合は以下の手順でAdministratorユーザーを作成します。 INDEX1 起動時のパラメーターの変更2 …