mysqld got signal 6

[kagami-h]

See
https://lists.osdn.me/mailman/archives/groonga-dev/2018-July/004645.html

180727_log.tar.gz

[kou]

ありがとうございます。

クラッシュしたクエリーが全部空白だけのクエリーみたいなんですよねぇ。関係あるのかしら。

% grep '^Query ' mysqld.log*
mysqld.log:Query (7f06736564e0): select * from tm_article_view where article_id = '747512' and delete_flag = '0'
mysqld.log:Query (7fd3facf4400): SELECT count(article_id) as cnt  FROM tm_ftext_view WHERE  MATCH(search_text) AGAINST('*D+ \"      \"' in boolean mode)  AND open_start_date > '2017-06-13 00:00:00'  AND open_start_date <= '2018-07-19 00:00:00'  ORDER BY open_start_date DESC,id DESC
mysqld.log_20180618191445:Query (7f165ac3be90): -- SearchModelClass_getSearchResult.sql   SELECT     count(article_id) as cnt FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"            \"' in boolean mode)
mysqld.log_20180618191445:Query (7f437978c8a0): 00 rw-p 00000000 00:00 0 
mysqld.log_20180618191445:Query (7fa36feb5160): -- SearchModelClass_getSearchResult.sql   SELECT     count(article_id) as cnt FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"                     \"' in boolean mode)
mysqld.log_20180618191445:Query (7f7b3cc70390): SELECT 'tm_ftext' AS ftext_type , article_id , title , open_start_date , NULL AS url  FROM tm_ftext_view WHERE  MATCH(search_text) AGAINST('*D+ \"                  \"' in boolean mode)  AND open_start_date > '2016-11-14 00:00:00'  AND open_start_date <= '2017-12-20 00:00:00'  ORDER BY open_start_date DESC,id DESC LIMIT 0,20
mysqld.log_20180618191445:Query (7f3f4c76a550): -- SearchModelClass_getSearchResult.sql   SELECT     'tm_article' AS article_type     , article_id     , title     , open_start_date     , first_img_path     , viewer_type     , body_view_type     , news_source     , NULL AS url FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"            \"' in boolean mode) ORDER BY open_start_date DESC LIMIT 0,20
mysqld.log_20180618191445:Query (7faeedd6cd80): -- SearchModelClass_getSearchResult.sql   SELECT     count(article_id) as cnt FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"      \"' in boolean mode)
mysqld.log_20180618191445:Query (7fe0a0b021a0): SELECT  'tm_ftext' AS ftext_type  , article_id   , title  , open_start_date  , NULL AS url  FROM tm_ftext_view  WHERE   MATCH(search_text) AGAINST('*D+ \"      \"' in boolean mode)     LIMIT 0,20
mysqld.log_20180618191445:Query (7fd579d4e130): /usr/sbin/mysqld(_Z12handle_queryP3THDP3LEXP12Query_resultyy+0x17d)[0xcfeaed]
mysqld.log_20180618191445:Query (7f157f4c2600): -- SearchModelClass_getSearchResult.sql   SELECT     count(article_id) as cnt FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"         \" \"      \"' in boolean mode)
mysqld.log_20180618191445:Query (7f81baae5ba0): -- SearchModelClass_getSearchResult.sql   SELECT     count(article_id) as cnt FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"                     \"' in boolean mode)
mysqld.log_20180618191445:Query (7ef93288f130): /usr/sbin/mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0x8d7)[0xcc5f77]
mysqld.log_20180618191445:Query (7f734426efa0): -- SearchModelClass_getSearchResult.sql   SELECT     'tm_article' AS article_type     , article_id     , title     , open_start_date     , first_img_path     , viewer_type     , body_view_type     , news_source     , NULL AS url FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"            \"' in boolean mode) ORDER BY open_start_date DESC LIMIT 0,20
mysqld.log_20180618191445:Query (7f13e5418830):             /var/lib/mysql/sierra_cms.mrn.00001FE
mysqld.log_20180618191445:Query (7f21473c20b0): -- SearchModelClass_getSearchResult.sql   SELECT     'tm_article' AS article_type     , article_id     , title     , open_start_date     , first_img_path     , viewer_type     , body_view_type     , news_source     , NULL AS url FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"               \"' in boolean mode) ORDER BY open_start_date DESC LIMIT 20,20
mysqld.log_20180618191445:Query (7f146f83e1a0): -- SearchModelClass_getSearchResult.sql   SELECT     count(article_id) as cnt FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"                  \" \"         \"' in boolean mode)
mysqld.log_20180618191445:Query (7efa00c12c60): -- SearchModelClass_getSearchResult.sql   SELECT     count(article_id) as cnt FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"      \"' in boolean mode)
mysqld.log_20180618191445:Query (7f79620770c0): -- SearchModelClass_getSearchResult.sql   SELECT     'tm_article' AS article_type     , article_id     , title     , open_start_date     , first_img_path     , viewer_type     , body_view_type     , news_source     , NULL AS url FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"            \"' in boolean mode) ORDER BY open_start_date DESC LIMIT 0,20
mysqld.log_20180618191445:Query (7efd07401110): -- SearchModelClass_getSearchResult.sql   SELECT     count(article_id) as cnt FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"         \" \"            \"' in boolean mode)
mysqld.log_20180618191445:Query (7f57b6941f60): -- SearchModelClass_getSearchResult.sql   SELECT     'tm_article' AS article_type     , article_id     , title     , open_start_date     , first_img_path     , viewer_type     , body_view_type     , news_source     , NULL AS url FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"      \"' in boolean mode) ORDER BY open_start_date DESC LIMIT 40,20
mysqld.log_20180618191445:Query (7fe5bbfcc5e0): -- SearchModelClass_getSearchResult.sql   SELECT     'tm_article' AS article_type     , article_id     , title     , open_start_date     , first_img_path     , viewer_type     , body_view_type     , news_source     , NULL AS url FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"         \"' in boolean mode) ORDER BY open_start_date DESC LIMIT 0,20
mysqld.log_20180618191445:Query (7f19e02816a0): -- SearchModelClass_getSearchResult.sql   SELECT     count(article_id) as cnt FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"      \"' in boolean mode)
mysqld.log_20180618191445:Query (7f0cbbb50990): -- SearchModelClass_getSearchResult.sql   SELECT     count(article_id) as cnt FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"                           \"' in boolean mode)
mysqld.log_20180618191445:Query (7f50f547e270): -- SearchModelClass_getSearchResult.sql   SELECT     count(article_id) as cnt FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"               \"' in boolean mode)
mysqld.log_20180618191445:Query (7ff6e5bc95c0): -- SearchModelClass_getSearchResult.sql   SELECT     'tm_article' AS article_type     , article_id     , title     , open_start_date     , first_img_path     , viewer_type     , body_view_type     , news_source     , NULL AS url FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"   \"' in boolean mode) ORDER BY open_start_date DESC LIMIT 0,20
mysqld.log_20180618191445:Query (7fd4a8c37f90): -- SearchModelClass_getSearchResult.sql   SELECT     count(article_id) as cnt FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"                     \"' in boolean mode)
mysqld.log_20180618191445:Query (7f3322168f70): -- SearchModelClass_getSearchResult.sql   SELECT     'tm_article' AS article_type     , article_id     , title     , open_start_date     , first_img_path     , viewer_type     , body_view_type     , news_source     , NULL AS url FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"                                    \"' in boolean mode) ORDER BY open_start_date DESC LIMIT 0,20
mysqld.log_20180618191445:Query (7f68b2147df0): -- SearchModelClass_getSearchResult.sql   SELECT     count(article_id) as cnt FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"      \"' in boolean mode)
mysqld.log_20180618191445:Query (7f22b8232220): -- SearchModelClass_getSearchResult.sql   SELECT     count(article_id) as cnt FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"                  \"' in boolean mode)
mysqld.log_20180618191445:Query (7fe710132880): -- SearchModelClass_getSearchResult.sql   SELECT     'tm_article' AS article_type     , article_id     , title     , open_start_date     , first_img_path     , viewer_type     , body_view_type     , news_source     , NULL AS url FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"                  \"' in boolean mode) ORDER BY open_start_date DESC LIMIT 0,20
mysqld.log_20180618191445:Query (7f45f1592270): -- SearchModelClass_getSearchResult.sql   SELECT     count(article_id) as cnt FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"         \"' in boolean mode)
mysqld.log_20180618191445:Query (7f3f068b80a0): -- SearchModelClass_getSearchResult.sql   SELECT     count(article_id) as cnt FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"      \"' in boolean mode)
mysqld.log_20180618191445:Query (7f88e1123740): -- SearchModelClass_getSearchResult.sql   SELECT     'tm_article' AS article_type     , article_id     , title     , open_start_date     , first_img_path     , viewer_type     , body_view_type     , news_source     , NULL AS url FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"         \"' in boolean mode) ORDER BY open_start_date DESC LIMIT 0,20
mysqld.log_20180618191445:Query (7fceefb143f0): -- SearchModelClass_getSearchResult.sql   SELECT     count(article_id) as cnt FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"      \" \"      \"' in boolean mode)
mysqld.log_20180618191445:Query (7fed6bcf7190): -- SearchModelClass_getSearchResult.sql   SELECT     'tm_article' AS article_type     , article_id     , title     , open_start_date     , first_img_path     , viewer_type     , body_view_type     , news_source     , NULL AS url FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"                           \"' in boolean mode) ORDER BY open_start_date DESC LIMIT 0,20
mysqld.log_20180618191445:Query (7f7e08901e00): -- SearchModelClass_getSearchResult.sql   SELECT     'tm_article' AS article_type     , article_id     , title     , open_start_date     , first_img_path     , viewer_type     , body_view_type     , news_source     , NULL AS url FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"   \"' in boolean mode) ORDER BY open_start_date DESC LIMIT 0,20
mysqld.log_20180618191445:Query (7f1209b3b350): -- SearchModelClass_getSearchResult.sql   SELECT     count(article_id) as cnt FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"      \"' in boolean mode)
mysqld.log_20180618191445:Query (7ff616391570): -- SearchModelClass_getSearchResult.sql   SELECT     'tm_article' AS article_type     , article_id     , title     , open_start_date     , first_img_path     , viewer_type     , body_view_type     , news_source     , NULL AS url FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"      \" \"         \"' in boolean mode) ORDER BY open_start_date DESC LIMIT 0,20

[kou]

Mroonga 6.09からMroonga 8.03にアップグレード。

db04の方は2018-07-05 15:25にアップグレード。

db05の方は2018-07-18 01:43にアップグレード。

[kou]

db05の方は2018-01-18 21:11に最初のクラッシュ。

[kou]

ハンドラーが複数のスレッドから使われていたらクラッシュしそうな気はするけど、そんなことあるのかしら。。。

[kagami-h]

クラッシュしたクエリーが全部空白だけのクエリーみたい

てっきり潰してログが出ているのかと思っていました。
他のログに無いか探しにいってみますね。

Mroonga 6.09からMroonga 8.03にアップグレード。

そうです。DB05側がマスターでした。
以降は Auto repair が failure になるごとに切り替えていると思います。

ハンドラーが複数のスレッドから使われていたらクラッシュ

んー、cron からなら mysql 経由。それ以外なら PHPのPDOからですので、何か変わった事はしていないつもりなのです。

[kou]

てっきり潰してログが出ているのかと思っていました。

あぁ、マルチバイト文字だから出ていないだけな可能性もあるかもしれませんね。。。

[kagami-h]

あぁ、マルチバイト文字だから出ていないだけな可能性もあるかもしれませんね。。。

なるほど。あいまいなのですが、他の方の Report でも同じようになっていたような気がします。

tar.gz 内の Log の DB05 側の直近のもの

mysqld.log_20180720014859:36978:Query (7f60ec471690): -- SearchModelClass_getSearchResult.sql   SELECT     count(article_id) as cnt FROM     tm_article_view WHERE     MATCH(search_text) AGAINST('*D+ \"         \"' in boolean mode)

これの検索キーワードは、「熱中症」でした。

（ちなみに検索キーワードのDBへの保存は失敗していました……そりゃそうか）

他に調べる点はありますか？

[kou]

そうですか、では関係なさそうですね。

残っているログだけでは情報が足りないことがわかったのでログを追加してもう一回再現させて情報を集めるのがよさそうに思うんですが、もうMroongaでは動かせないということなので手詰まりかなぁという感じです。

[kagami-h]

ありがとうございます。
なるほど。
groonga-debuginfoとmysql57-community-mroonga-debuginfo
を yum で入れるだけで、log level の変更等は不要でしょうか？

実現はかなり困難なのですが、一応念のためまで。

[kou]

いえ、Mroongaにもログ出力コードを追加しないといけなそうです。

[kagami-h]

何か私のほうで追加が可能でしょうか？

[kou]

すみません、見逃していました。

ha_mroonga.cppの怪しげなところにGRN_LOG(ctx, GRN_LOG_DEBUG, "...");みたいなのを追加していく感じなので追加すること自体はできますが、どういう情報を残すのかを検討するのは難しそうです。。。

次のMroongaのリリースまでになにかしらログを仕込んでおくのでそれを参考にしてもらうとかならいけるかも！？

[kagami-h]

ありがとうございます。
では、次の Mroonga のリリースノートを確認したいと思います。

[kenhys]

@kagami-h このissueってもう閉じてしまってもいいやつでしょうか？

[kagami-h]

そうですね、一旦閉じてしまってくださ～い。
ちなみにログ出力コードがどうなったか分かると助かります。