yoku ts.
yoku0****@gmail*****
2015年 5月 15日 (金) 10:26:34 JST
呼ばれた気がしました。こんにちは。
試しても再現させられなかったのでもにょもにょしていたのですが、わかりそうなところだけでも。
>> ところで、手元だと
>>
>>> Error 'Data truncated for column 't_date' at row 1' on query. Default database: 'db_test'.
>>
>> というようにErrorではなくWarning扱いになっていたのですが、レ
>> プリケーションが切断されるのはエラー扱いになっているから、、、
>> だったりするのかしら。
>
> 上のメッセージは、SHOW SLAVE STATUS で表示される方なのです。
> 確かにSQL実行時の方は warning なのですよねぇ。Slave側 でも格納されていますし。
warningになるものがerrorになるといえばsql_mode= 'STRICT_ALL_TABLES'あたりが有名で、
* マスターではsql_mode != 'STRICT_ALL_TABLES'
かつ
* スレーブのSQLスレッドでsql_mode= 'STRICT_TRANS_TABLES'
だとこういう動作になりそうな気がしなくもないんですが、
マスターで更新した時に「その時のsql_mode」も一緒にバイナリーログに記録するため、
マスター/スレーブ間でsql_modeの設定が違ってもこういう風にはならないはずです。
ので、手元では再現していません(´･ω･｀)
Mroongaがトランザクション非対応なあたりで、
マスターでsql_modeをガリガリ書き換えながら更新をかけると混ざったりするのかなぁと思ったり思わなかったりしています。
どうなんだろう。
再現環境下でのSHOW SLAVE STATUSのIPアドレス以外のまるまるの出力と、
エラーが起こったイベントの前後1イベントくらいずつのマスターのバイナリーログと
スレーブのリレーログとかもらえると深追いできるかも知れません。
ただ、
>> この際、スレーブ側へのレコード登録は「0000-01-01 00:00:00」で成功するが、
>> レプリケーションは切断される。
>>
>> Error 'Data truncated for column 't_date' at row 1' on query. Default database: 'db_test'.
>> Query: 'INSERT INTO tbl_test_pat_0001 (t_key, t_date) VALUES ('test1', '0000-00-00')'
スレーブにレコードの登録が成功する、というのがまたわからないんですよねぇ。。
Mroongaはトランザクション非対応なので、Mroonga側で書き込みが終わったあとに
Handlerのどこかがエラーになるならそうなりそうですけども。。
> my.cnf で何か変更している点があるならば、
>
> transaction_isolation = READ-COMMITTED
> slave_exec_mode = idempotent
>
> ここらへんを変えていますが、関係ありそうでしょうか？
binlog_formatは指定していませんか？ (暗黙のデフォルトはSTATEMENT)
であれば、関係ないと思います（MIXEDの場合、READ-COMMITTEDだとRBRに変わる）
ところで、slave_exec_modeってNDBCLUSTER(MySQL Cluster)用のパラメーターなんですが、
NDBCLUSTERのmysqldを使ってたりします？
> >>> collisions(xxxxxxxx/xxxxxxx): lock failed 1000 times
> >>> が頻発するのも気になっていますが。
> >>
> >> これ、どういうときに発生しているかわかりますか？
ウチでも更新トラフィックが多い時間帯はたまに出てます。
> MySQLって書き込み回数とかの統計情報ってとれるんでしたっけ。
> とれるなら書き込み頻度を確認すると更新頻度が影響してそうかわ
> かりそうだなぁと思いました。
Handler_writeとかHandler_updateはどうですか？
役に立たなくてすいません(´･ω･｀)
yoku0825,
2015年5月15日 0:28 Kouhei Sutou <kou****@clear*****>:
> 須藤です。
>
> In <20150****@domai*****>
> "[groonga-dev,03228] Re: mroongaで同一レコードの登録、削除、登録を行うとユニークキー重複エラー発生" on Thu, 14 May 2015 12:18:52 +0900,
> 各務 洋 <kagam****@outwa*****> wrote:
>
>>>> となるので、truncate する前の値で index を作成し、削除し損ねているのではないのでしょうか？
>>>
>>> INSERTするときは'0000-00-00'相当の値で、DELETEするとき
>>> は'0000-01-01'相当の値でインデックスを削除しようとして失敗し
>>> ているような感じでした。
>>>
>>> INSERTするときもMroongaが認識した値でインデックスに登録する
>>> ようにしておけばよさそう。。。なのかしら。
>>
>> これだと思います。
>
> そうして直しました。
> 次回リリースに含まれます。
>
>>> ところで、手元だと
>>>
>>>> Error 'Data truncated for column 't_date' at row 1' on query. Default database: 'db_test'.
>>>
>>> というようにErrorではなくWarning扱いになっていたのですが、レ
>>> プリケーションが切断されるのはエラー扱いになっているから、、、
>>> だったりするのかしら。
>>
>> 上のメッセージは、SHOW SLAVE STATUS で表示される方なのです。
>> 確かにSQL実行時の方は warning なのですよねぇ。Slave側 でも格納されていますし。
>>
>> my.cnf で何か変更している点があるならば、
>>
>> transaction_isolation = READ-COMMITTED
>> slave_exec_mode = idempotent
>>
>> ここらへんを変えていますが、関係ありそうでしょうか？
>
> yoku0825さんがわかったりするのかしら。。。
>
> ところで、スレーブのログにはなにか残っていませんか？
> 接続されるのはmysqldがクラッシュしたときが多くて、そのときは
> ログになにか出ているんです。
>
>
>> mroonga テーブルの破損後だと、MySQLもたまにクラッシュしているようです。
>> でもクラッシュしない事の方が多いです。
>>
>> ただ、これだと比較的分かりやすいのですが、多いパターン順だと。
>>
>> INSERT 出来なくなる。
>> Unique キーで SELECT 結果が0件になるが、主キーでは SELECT できる。
>> ↑DELETE も同様。
>>
>> 上記が単体、または組み合わせで発生して、DBの応答待ちや Load Average の
>> 上昇といった事が多いです。
>>
>> ※ MATCH AGAINST ではなく、= での条件指定がほとんどです。
>> ※ UPDATE も出来なくなりますが（応答待ち）、通常使用だとこのテーブルは
>> UPDATE しないのです。
>
> テーブルが破損していると何が起きてもおかしくないので、まずは
> 破損する原因を調べて直してそれでも発生するか確認したほうがよ
> さそうだなぁと思いました。
>
>>>> TIMESTAMP型ではまだ見つかっておりません。
>>>
>>> これも不正な値（Mroongaが扱えない値）関連なんですかねぇ。
>>
>> 今まで格納された値が不整合というのは記憶にないのです。
>
> あ、そうではなくて、0000-00-00みたいな値ということでした。
>
>> 新テーブルの schema を作成し、
>> INSERT INTO 新テーブル SELECT * FROM 旧テーブル;
>> ALTER TABLE RENAME の差し替えで、修復完了しています。
>>
>> ※ ALTER TABLE 旧テーブル ENGINE mroonga; での修復は怖くてまだ試していません。
>
> あれ、ENGINEが同じでもなにか起きるんでしたっけ。
> たぶん、最後のALTER TABLEは内部的には一時テーブルを作ってそ
> こにデータをコピーしてからリネームというロジックになるケース
> だと思うので、手動でやっているやつと同じ動作になるんじゃない
> かと思います。
>
> ただ、はじめてやるときは不安だと思うので、余裕があるときにバッ
> クアップをとった状態で試してみてください。
>
>> あと、出来るかぎり他のテストも行ってみます。
>
> ありがとうございます！
>
>
>>>> collisions(xxxxxxxx/xxxxxxx): lock failed 1000 times
>>>> が頻発するのも気になっていますが。
>>>
>>> これ、どういうときに発生しているかわかりますか？
>>
>> 更新が少なそうな時間帯には発生しにくい。ぐらいしか分からないのです。
>> （常時、なんらかの処理が稼働しているので）
>> もっと具体的なログを出す方法があれば、ご教示いただけると助かります。
>
> MySQLって書き込み回数とかの統計情報ってとれるんでしたっけ。
> とれるなら書き込み頻度を確認すると更新頻度が影響してそうかわ
> かりそうだなぁと思いました。
>
>> 確かに複数の接続で処理は行っているのですが、その際も Unique キーの決め
>> うちでの DELETE / INSERT か、日付型での範囲検索での DELETE です。
>> 範囲検索の方は同時実行は行わない……はずです。
>
> であればDELETE/INSERTの方があやしそうですね。
> もしかしたら、そっちが同じカラムや同じインデックスを複数のスレッ
> ドから同時に更新してロックが競合しやすくなっているのかもしれ
> ません。
>
>> P.S
>> 発生している環境は複数で、いずれもレプリケーション構成。
>> 本番環境がほとんどで、ステージ環境ではまれ。
>> Cent OS 6 が主で 5 と 7 もある。
>> MySQL 5.6 が主で 5.5 が 2 構成だけ。
>> mroonga は 4.01～。
>
> 本番環境がほとんどということなので、負荷が関係ありそうな気が
> しますね。
>
>
> --
> 須藤 功平 <kou****@clear*****>
> 株式会社クリアコード <http://www.clear-code.com/>
>
> Groongaベースの全文検索システムを総合サポート:
> http://groonga.org/ja/support/
> パッチ採用 - プログラミングが楽しい人向けの採用プロセス:
> http://www.clear-code.com/recruitment/
> プログラミングが好きな学生のための勉強会:
> http://www.seplus.jp/sezemi/
>
> _______________________________________________
> groonga-dev mailing list
> groon****@lists*****
> http://lists.osdn.me/mailman/listinfo/groonga-dev