各務 洋
kagam****@outwa*****
2018年 7月 25日 (水) 13:02:16 JST
お世話になります、各務です。
mysqld が頻繁に crash し同時に Mroonga のテーブルを破損するようになっ
たので、お知恵を拝借したいです。
環境：
MySQL : 5.7.22
Mroonga : 8.03
mroonga_libgroonga_version : 8.0.4
mroonga_version : 8.03
CentOS : 7.5
Master / Slave の2台構成
現象：
Master 側の mysqld が ここ1ヶ月で頻繁に crash するようになり、その後の
自動再起動時に毎回 Mroonga の Auto repair が failure になります。
発生時間は不定ですが、概ね負荷が高くなる際に発生。
但し、Slave 側では発生しません。
障害発生時に縮退させるため、Master / Slave は交互に入れ替えますが、
いずれも Master 側でのみ発生します。
Auto repair が failure の際は、datadir は毎回作り直しています。
この時の mysqld の log 内で Error in として出るものは、
Error in `/usr/sbin/mysqld': corrupted double-linked list:
が 44回
Error in `/usr/sbin/mysqld': double free or corruption (!prev):
が 16回
です。この回数は直近6ヶ月ほどの間で、現在の環境に update する前のもの
も含んでおりますが、今月に行った update 後も改善されないため含めて報告
させていただきました。
mysqld の log で見える Query は 全文検索が多いのですが、それ以外の
WHERE や JOIN の SQL も含まれておりますが、概ね Mroonga のテーブルの
SELECT 文です。
昨年末からちょいちょい crash していたのですが、Auto repair が発動と修
復に失敗するようになったのはここ1ヶ月位です。
現在、テーブルを InnoDB に変換することで crash は発生しておりません。
下記のログは直近にあったものから1件分を切り出した形です。
他も概ね同じような感じですが、何か必要な情報がございましたらご指摘いただけたらと存じます。
いかがでしょうか？
以上、お手数ですが、ご検討いただければ幸いです。
-- groonga.log -----------------------------------------------------------------
〜〜 crash 前には特に予兆が無い
2018-07-20 00:12:58.117113|n|ab876780|mroonga 8.03 started.
2018-07-20 00:12:58.125081|n|ab876780|log level is 'NOTICE'
2018-07-20 00:13:18.332164|n|1c04e700|Auto repair is started: <./sierra_cms/tm_article_view>
2018-07-20 00:13:19.433459|n|1c04e700|io(sierra_cms.mrn.0000146) collisions(1000/1): lock failed 1000 times
2018-07-20 00:13:51.110813|w|1c04e700|[DB Locked] time out(30000): io(sierra_cms.mrn.0000146) collisions(30000/1)
2018-07-20 00:13:51.110882|e|1c04e700|grn_io_lock failed
2018-07-20 00:13:51.144837|e|1c04e700|/lib64/libgroonga.so.0(grn_io_lock+0x2ee) [0x7fb22ca0f35e]
2018-07-20 00:13:51.144870|e|1c04e700|/lib64/libgroonga.so.0(grn_table_delete_by_id+0xcc) [0x7fb22c8c04fc]
2018-07-20 00:13:51.144880|e|1c04e700|/usr/lib64/mysql/plugin/ha_mroonga.so(_ZN3mrn10Operations6repairEPKcm+0x200) [0x7fb22d2cfa20]
2018-07-20 00:13:51.144887|e|1c04e700|/usr/lib64/mysql/plugin/ha_mroonga.so(_ZN10ha_mroonga12storage_openEPKcij+0x181) [0x7fb22d2b95c1]
2018-07-20 00:13:51.144894|e|1c04e700|/usr/lib64/mysql/plugin/ha_mroonga.so(_ZN10ha_mroonga4openEPKcij+0x11d) [0x7fb22d2c08ed]
2018-07-20 00:13:51.144901|e|1c04e700|/usr/sbin/mysqld(_ZN7handler7ha_openEP5TABLEPKcii+0x33) [0x800fc3]
2018-07-20 00:13:51.144908|e|1c04e700|/usr/sbin/mysqld(_Z21open_table_from_shareP3THDP11TABLE_SHAREPKcjjjP5TABLEb+0x777) [0xd64e97]
2018-07-20 00:13:51.144915|e|1c04e700|/usr/sbin/mysqld(_Z10open_tableP3THDP10TABLE_LISTP18Open_table_context+0xe8b) [0xc7002b]
2018-07-20 00:13:51.144921|e|1c04e700|/usr/sbin/mysqld(_Z11open_tablesP3THDPP10TABLE_LISTPjjP19Prelocking_strategy+0x612) [0xc76fe2]
2018-07-20 00:13:51.144928|e|1c04e700|/usr/sbin/mysqld(_Z21open_tables_for_queryP3THDP10TABLE_LISTj+0x5a) [0xc7793a]
2018-07-20 00:13:51.144935|e|1c04e700|/usr/sbin/mysqld() [0x7758ba]
2018-07-20 00:13:51.144941|e|1c04e700|/usr/sbin/mysqld(_Z21mysql_execute_commandP3THDb+0x446c) [0xcca72c]
2018-07-20 00:13:51.144954|e|1c04e700|/usr/sbin/mysqld(_Z11mysql_parseP3THDP12Parser_state+0x3ad) [0xcccc5d]
2018-07-20 00:13:51.144965|e|1c04e700|/usr/sbin/mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0xa7d) [0xccd7bd]
2018-07-20 00:13:51.144972|e|1c04e700|/usr/sbin/mysqld(_Z10do_commandP3THD+0x19f) [0xccf1af]
2018-07-20 00:13:51.144979|e|1c04e700|/usr/sbin/mysqld(handle_connection+0x288) [0xd8f998]
2018-07-20 00:13:51.145020|n|1c04e700|Auto repair is done: <./sierra_cms/tm_article_view>: failure
2018-07-20 00:13:51.145090|n|140e7700|Auto repair is started: <./sierra_cms/tm_article_view>
2018-07-20 00:13:52.265235|n|140e7700|io(sierra_cms.mrn.0000146) collisions(31000/2): lock failed 1000 times
〜〜 以降修復までこれの繰り返し
-- groonga.log 終わり -----------------------------------------------------------
-- mysqld.log -------------------------------------------------------------------
*** Error in `/usr/sbin/mysqld': corrupted double-linked list: 0x00007f6088129e50 ***
======= Backtrace: =========
/lib64/libc.so.6(+0x7b194)[0x7f6586eff194]
/lib64/libc.so.6(+0x7d0e5)[0x7f6586f010e5]
/lib64/libgroonga.so.0(grn_free_default+0x23)[0x7f62eae0e743]
/lib64/libgroonga.so.0(grn_obj_close+0x42b)[0x7f62eae2ee6b]
/usr/lib64/mysql/plugin/ha_mroonga.so(+0x217be)[0x7f63072f67be]
/usr/lib64/mysql/plugin/ha_mroonga.so(+0x21859)[0x7f63072f6859]
/usr/sbin/mysqld(_ZN15Item_func_match7cleanupEv+0x62)[0x87b6a2]
/usr/sbin/mysqld(_ZN11Query_arena10free_itemsEv+0x30)[0xc85bc0]
/usr/sbin/mysqld(_ZN3THD19cleanup_after_queryEv+0x65)[0xc85c45]
/usr/sbin/mysqld(_Z11mysql_parseP3THDP12Parser_state+0x186)[0xccca36]
/usr/sbin/mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0xa7d)[0xccd7bd]
/usr/sbin/mysqld(_Z10do_commandP3THD+0x19f)[0xccf1af]
/usr/sbin/mysqld(handle_connection+0x288)[0xd8f998]
/usr/sbin/mysqld(pfs_spawn_thread+0x1b4)[0x1273324]
/lib64/libpthread.so.0(+0x7dc5)[0x7f65884bedc5]
/lib64/libc.so.6(clone+0x6d)[0x7f6586f7aced]
======= Memory map: ========
〜〜 中略 〜〜
7f6087800000-7f6087c00000 rw-s 17443000 fd:04 543579245 /var/lib/mysql/sierra_cms.mrn.00001FD
7f6087c00000-7f6088000000 rw-p 00000000 00:00 0
7f6088000000-7f608bffe000 rw-p 00000000 00:00 0
7f608bffe000-7f608c000000 ---p 00000000 00:00 0
〜〜 中略 〜〜
15:12:48 UTC - mysqld got signal 6 ;
This could be because you hit a bug. It is also possible that this binary
or one of the libraries it was linked against is corrupt, improperly built,
or misconfigured. This error can also be caused by malfunctioning hardware.
Attempting to collect some information that could help diagnose the problem.
As this is a crash and something is definitely wrong, the information
collection process might fail.
key_buffer_size=268435456
read_buffer_size=1048576
max_used_connections=159
max_threads=664
thread_count=7
connection_count=7
It is possible that mysqld could use up to
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 1630897 K bytes of memory
Hope that's ok; if not, decrease some variables in the equation.
Thread pointer: 0x7f610c8d8540
Attempting backtrace. You can use the following information to find out
where mysqld died. If you see no messages after this, something went
terribly wrong...
stack_bottom = 7f618362be70 thread_stack 0x40000
/usr/sbin/mysqld(my_print_stacktrace+0x3b)[0xefc05b]
/usr/sbin/mysqld(handle_fatal_signal+0x461)[0x7b3511]
/lib64/libpthread.so.0(+0xf100)[0x7f65884c6100]
/lib64/libc.so.6(gsignal+0x37)[0x7f6586eb95f7]
/lib64/libc.so.6(abort+0x148)[0x7f6586ebace8]
/lib64/libc.so.6(+0x75327)[0x7f6586ef9327]
/lib64/libc.so.6(+0x7b194)[0x7f6586eff194]
/lib64/libc.so.6(+0x7d0e5)[0x7f6586f010e5]
/lib64/libgroonga.so.0(grn_free_default+0x23)[0x7f62eae0e743]
/lib64/libgroonga.so.0(grn_obj_close+0x42b)[0x7f62eae2ee6b]
/usr/lib64/mysql/plugin/ha_mroonga.so(+0x217be)[0x7f63072f67be]
/usr/lib64/mysql/plugin/ha_mroonga.so(+0x21859)[0x7f63072f6859]
/usr/sbin/mysqld(_ZN15Item_func_match7cleanupEv+0x62)[0x87b6a2]
/usr/sbin/mysqld(_ZN11Query_arena10free_itemsEv+0x30)[0xc85bc0]
/usr/sbin/mysqld(_ZN3THD19cleanup_after_queryEv+0x65)[0xc85c45]
/usr/sbin/mysqld(_Z11mysql_parseP3THDP12Parser_state+0x186)[0xccca36]
/usr/sbin/mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0xa7d)[0xccd7bd]
/usr/sbin/mysqld(_Z10do_commandP3THD+0x19f)[0xccf1af]
/usr/sbin/mysqld(handle_connection+0x288)[0xd8f998]
/usr/sbin/mysqld(pfs_spawn_thread+0x1b4)[0x1273324]
/lib64/libpthread.so.0(+0x7dc5)[0x7f65884bedc5]
/lib64/libc.so.6(clone+0x6d)[0x7f6586f7aced]
Trying to get some variables.
Some pointers may be invalid and cause the dump to abort.
Query (7f60ec471690): -- SearchModelClass_getSearchResult.sql SELECT count(article_id) as cnt FROM tm_article_view WHERE MATCH(search_text) AGAINST('*D+ \" \"' in boolean mode)
Connection ID (thread ID): 3161938
Status: NOT_KILLED
-- mysqld.log 終わり -----------------------------------------------------------
----
各務
kagam****@outwa*****