[groonga-dev,04813] Re: [ii][update][one] failed to decode / failed to merge chunk / failed to flush a bufferが出たときについて

Back to archive index
Sutou Kouhei kou****@clear*****
2020年 7月 3日 (金) 09:35:06 JST


須藤です。

追加情報ありがとうございます!

前に提供してもらった壊れたDBは今月中には調査したい気持ちです!

In <CANM+Hhd7wNt+KE-vAqJdph8x2DYMSiqWu_zU3FY****@mail*****>
  "[groonga-dev,04812] Re: [ii][update][one] failed to decode / failed to merge chunk / failed to flush a bufferが出たときについて" on Fri, 3 Jul 2020 01:02:04 +0900,
  Naoya Murakami <visio****@gmail*****> wrote:

> 村上です。
> 
> こちらに関して、先日1件、マージに失敗するのが再発生したのですが、
> こちらについてはマージに失敗する前、思ったよりメモリを使いすぎていて
> mmapに失敗してました。
> 
> このタイミングでmmapに失敗すると100%チャンクかバッファーが壊れるのかまでは
> 特定できていませんが、とりあえず、vm.max_map_countをさらに上げることと、
> 更新時に同時に使うメモリが大きくなりすぎないようにして再発が抑えられないか様子
> を見てみます。
> 
> なお、この壊れたDBは再作成して手元には残っていません。
> 
> 2020-06-25 12:17:50.987229|A|20927|c4108700:
> mmap(4194304,1835,897585152)=Cannot allocate memory <463439425536>
> 2020-06-25 12:17:50.990443|A|20927|c4108700:
> /usr/lib/x86_64-linux-gnu/libgroonga.so.0(grn_ctx_log_back_trace+0x3a)
> [0x7f55c5c5a3fa]
> 2020-06-25 12:17:50.990450|A|20927|c4108700:
> /usr/lib/x86_64-linux-gnu/libgroonga.so.0(grn_io_seg_map_+0x6d2)
> [0x7f55c5da2cc2]
> 2020-06-25 12:17:50.990455|A|20927|c4108700:
> /usr/lib/x86_64-linux-gnu/libgroonga.so.0(grn_io_win_map+0xd32)
> [0x7f55c5da50a2]
> 2020-06-25 12:17:50.990459|A|20927|c4108700:
> /usr/lib/x86_64-linux-gnu/libgroonga.so.0(+0x2fee0b) [0x7f55c5d6ee0b]
> 2020-06-25 12:17:50.990463|A|20927|c4108700:
> /usr/lib/x86_64-linux-gnu/libgroonga.so.0(+0x301d38) [0x7f55c5d71d38]
> 2020-06-25 12:17:50.990467|A|20927|c4108700:
> /usr/lib/x86_64-linux-gnu/libgroonga.so.0(grn_ii_update_one+0x67e)
> [0x7f55c5d7cace]
> 2020-06-25 12:17:50.990472|A|20927|c4108700:
> /usr/lib/x86_64-linux-gnu/libgroonga.so.0(grn_ii_column_update+0xc60)
> [0x7f55c5d86a90]
> 2020-06-25 12:17:50.990476|A|20927|c4108700:
> /usr/lib/x86_64-linux-gnu/libgroonga.so.0(grn_obj_default_set_value_hook+0x98)
> [0x7f55c5c6ae68]
> 2020-06-25 12:17:50.990480|A|20927|c4108700:
> /usr/lib/x86_64-linux-gnu/libgroonga.so.0(grn_obj_set_value+0x177b)
> [0x7f55c5c7abdb]
> 2020-06-25 12:17:50.990484|A|20927|c4108700:
> /usr/local/mysql/lib/plugin/ha_mroonga.so(_ZN10ha_mroonga17storage_write_rowEPh+0x934)
> [0x7f55f4089e04]
> 2020-06-25 12:17:50.990489|A|20927|c4108700:
> /usr/local/mysql/bin/mysqld(_ZN7handler12ha_write_rowEPh+0x198)
> [0x5584008c9758]
> 2020-06-25 12:17:50.990493|A|20927|c4108700:
> /usr/local/mysql/bin/mysqld(_Z12write_recordP3THDP5TABLEP9COPY_INFOS4_+0x638)
> [0x558400edb4a8]
> 2020-06-25 12:17:50.990497|A|20927|c4108700:
> /usr/local/mysql/bin/mysqld(_ZN14Sql_cmd_insert12mysql_insertEP3THDP10TABLE_LIST+0x931)
> [0x558400edcd51]
> 2020-06-25 12:17:50.990501|A|20927|c4108700:
> /usr/local/mysql/bin/mysqld(_ZN14Sql_cmd_insert7executeEP3THD+0xf2)
> [0x558400eddac2]
> 2020-06-25 12:17:50.990505|A|20927|c4108700:
> /usr/local/mysql/bin/mysqld(_Z21mysql_execute_commandP3THDb+0x3570)
> [0x558400d59c10]
> 2020-06-25 12:17:50.990510|A|20927|c4108700:
> /usr/local/mysql/bin/mysqld(_Z11mysql_parseP3THDP12Parser_state+0x38d)
> [0x558400d5d41d]
> 2020-06-25 12:17:50.990515|C|20927|c4108700: mmap failed!!! in
> GRN_IO_SEG_REF(0x7f552f532520, 214, 1): Cannot allocate memory
> 2020-06-25 12:17:50.990527|A|20927|c4108700: [ii][chunk][merge] failed to
> allocate a source chunk: <vgram_terms.ftext4>: <"段">(2148099822):
> record:<58490799>, segment:<3507664>, size:<2533>
> 
> 2020-06-25 12:17:50.994603|A|20927|c4108700:
> /usr/lib/x86_64-linux-gnu/libgroonga.so.0(grn_ctx_log_back_trace+0x3a)
> [0x7f55c5c5a3fa]
> 2020-06-25 12:17:50.994610|A|20927|c4108700:
> /usr/lib/x86_64-linux-gnu/libgroonga.so.0(+0x2ff76a) [0x7f55c5d6f76a]
> 2020-06-25 12:17:50.994614|A|20927|c4108700:
> /usr/lib/x86_64-linux-gnu/libgroonga.so.0(+0x301d38) [0x7f55c5d71d38]
> 2020-06-25 12:17:50.994618|A|20927|c4108700:
> /usr/lib/x86_64-linux-gnu/libgroonga.so.0(grn_ii_update_one+0x67e)
> [0x7f55c5d7cace]
> 2020-06-25 12:17:50.994623|A|20927|c4108700:
> /usr/lib/x86_64-linux-gnu/libgroonga.so.0(grn_ii_column_update+0xc60)
> [0x7f55c5d86a90]
> 2020-06-25 12:17:50.994631|A|20927|c4108700:
> /usr/lib/x86_64-linux-gnu/libgroonga.so.0(grn_obj_default_set_value_hook+0x98)
> [0x7f55c5c6ae68]
> 2020-06-25 12:17:50.994635|A|20927|c4108700:
> /usr/lib/x86_64-linux-gnu/libgroonga.so.0(grn_obj_set_value+0x177b)
> [0x7f55c5c7abdb]
> 2020-06-25 12:17:50.994639|A|20927|c4108700:
> /usr/local/mysql/lib/plugin/ha_mroonga.so(_ZN10ha_mroonga17storage_write_rowEPh+0x934)
> [0x7f55f4089e04]
> 2020-06-25 12:17:50.994644|A|20927|c4108700:
> /usr/local/mysql/bin/mysqld(_ZN7handler12ha_write_rowEPh+0x198)
> [0x5584008c9758]
> 2020-06-25 12:17:50.994648|A|20927|c4108700:
> /usr/local/mysql/bin/mysqld(_Z12write_recordP3THDP5TABLEP9COPY_INFOS4_+0x638)
> [0x558400edb4a8]
> 2020-06-25 12:17:50.994652|A|20927|c4108700:
> /usr/local/mysql/bin/mysqld(_ZN14Sql_cmd_insert12mysql_insertEP3THDP10TABLE_LIST+0x931)
> [0x558400edcd51]
> 2020-06-25 12:17:50.994656|A|20927|c4108700:
> /usr/local/mysql/bin/mysqld(_ZN14Sql_cmd_insert7executeEP3THD+0xf2)
> [0x558400eddac2]
> 2020-06-25 12:17:50.994661|A|20927|c4108700:
> /usr/local/mysql/bin/mysqld(_Z21mysql_execute_commandP3THDb+0x3570)
> [0x558400d59c10]
> 2020-06-25 12:17:50.994665|A|20927|c4108700:
> /usr/local/mysql/bin/mysqld(_Z11mysql_parseP3THDP12Parser_state+0x38d)
> [0x558400d5d41d]
> 2020-06-25 12:17:50.994669|A|20927|c4108700:
> /usr/local/mysql/bin/mysqld(_Z16dispatch_commandP3THDPK8COM_DATA19enum_server_command+0xdd2)
> [0x558400d5e322]
> 2020-06-25 12:17:50.994673|A|20927|c4108700:
> /usr/local/mysql/bin/mysqld(_Z10do_commandP3THD+0x220) [0x558400d5fa50]
> 2020-06-25 12:17:50.994680|e|20927|c4108700: [ii][buffer][merge] failed to
> merge chunk: <vgram_terms.ftext4>: <"段">(2148099822): chunk:<379>,
> n-chunks:<702>
> 
> 
> 2020年5月19日(火) 9:33 Sutou Kouhei <kou****@clear*****>:
> 
>> 須藤です。
>>
>> > 後者のデータを可能な限り、DBと更新クエリをコンパクト化し、
>> > 別途手段にて共有させていただきます。
>> > 少々時間がかかるかもしれません。
>>
>> この問題の再現作成用にちょっとしたスクリプトがあるのでそれを
>> 使えるかもしれません。
>>
>> https://github.com/groonga/groonga/blob/master/tools/copy-related-files.rb
>> を使うとDBの中の必要な部分だけコピーできます。これを使って更
>> 新処理を次のようにします。
>>
>>   1. 元のDBから必要な部分だけをコピーする
>>   2. 更新データを保存する
>>   3. 通常の更新処理をする
>>   4. 問題が発生したら1.と2.が欲しかった情報
>>
>> あと、もしかしたら、問題発生のチェックにindex_column_diffを
>> 使えるかもしれません。
>>
>> ということでこんなスクリプトになります。
>>
>> reproduced=no
>> if [ -d db.reproduced ]; then
>>   reproduced=yes
>> fi
>> if [ "${reproduced}" = "no" ]; then
>>   rm -rf db.copy
>>   ruby copy-related-files.rb \
>>     --destination=db.copy \
>>     --target=vgram_terms.description7
>>     db
>> fi
>> # 通常の更新用データ生成
>> generate-load-data.sh > load.grn
>> # 問題が発生したらここでブロックしてしまうかも
>> groonga --log-file db/log --file load.grn db/db
>> if [ "${reproduced}" = "no" ]; then
>>   n_broken_tokens=$(groonga db/db index_column_diff
>> vgram_terms.description7 | jq '.[1][].token.value' | wc -l)
>>   if [ ${n_broken_tokens} -ne 0 -o grep -q "failed to decode" db/log ];
>> then
>>     echo "reproduced!"
>>     mv db.copy db.reproduced
>>     mv load.grn load.reproduced.grn
>>   fi
>> fi
>>
>>
>> In <CANM+HhdEFvSQUcbY7Bdi3wMQeSefPkB_Qez6k****@mail*****>
>>   "[groonga-dev,04806] Re: [ii][update][one] failed to decode / failed to
>> merge chunk / failed to flush a bufferが出たときについて" on Tue, 19 May 2020
>> 07:35:29 +0900,
>>   Naoya Murakami <visio****@gmail*****> wrote:
>>
>> > 村上です。
>> >
>> > 残念ながら後者ですね。
>> >
>> > 後者のデータを可能な限り、DBと更新クエリをコンパクト化し、
>> > 別途手段にて共有させていただきます。
>> > 少々時間がかかるかもしれません。
>> >
>> > 前者は複数のDBで同じ更新をずっと流してもあるDBでは起きて、
>> > 他のDBでは起きないということが結構あるので、再現がなかなか
>> > 難しそうなんですよね。
>> >
>> > 時間できたら検証環境作って、更新データをまとめて動的更新し
>> > 続けて再現できないか試してみます。
>> >
>> >
>> > 2020年5月19日(火) 6:49 Sutou Kouhei <kou****@clear*****>:
>> >
>> >> 須藤です。
>> >>
>> >> これ、最近原因を調べている(けどまだわかっていない)問題な気
>> >> がします。
>> >>
>> >> >>> 現状、同じ更新をすれば、必ずfailed to decodeになるデータベースは用意できますが、
>> >> >>> 参考になりますかね。
>> >>
>> >> これは、次の2つのデータがあるということですか?
>> >>
>> >>   * 問題のない(エラーになる前の)DB
>> >>   * ↑に入れるとこのエラーが出る更新データ
>> >>
>> >> であれば提供してもらえると助かります。
>> >>
>> >> それとも次のデータですか?
>> >>
>> >>   * エラーになった後のDB
>> >>   * ↑に再度入れるとこのエラーが再発する更新データ
>> >>
>> >> こちらでも提供してもらえると少し助かります。
>> >>
>> >> エラーになった後のDBは入手できそうなのですが、再発用の更新デー
>> >> タは入手できそうなので、1つデータが増えて助かります。
>> >>
>> >>
>> >> In <CANM+****@mail*****>
>> >>   "[groonga-dev,04804] Re: [ii][update][one] failed to decode / failed
>> to
>> >> merge chunk / failed to flush a bufferが出たときについて" on Mon, 18 May 2020
>> >> 19:55:58 +0900,
>> >>   Naoya Murakami <visio****@gmail*****> wrote:
>> >>
>> >> > 村上です。
>> >> >
>> >> > 自己レスばかりですいません。。
>> >> >
>> >> > term_idはmax_idで&を取る仕様みたいで実際は171ですのでbufferは問題なさそうでした。
>> >> > 以下のgrn_p_dec()内のunpackで失敗しているみたいなのでやはりチャンクがおかしそうですね。
>> >> >
>> >>
>> https://github.com/groonga/groonga/blob/6866ef08d386e63a7a26bae8fdaeb8f15a840ed9/lib/ii.c#L2237
>> >> >
>> >> > 壊し方を再現できたらまたご連絡いたします。
>> >> >
>> >> > 2020年5月18日(月) 19:13 Naoya Murakami <visio****@gmail*****>:
>> >> >
>> >> >> 村上です。
>> >> >>
>> >> >> buffer_data->term->tidが2147483819でなぜか2GiBちょいですね。
>> >> >> 実際のこれのlexiconのkey数は126447481で"9"というキーのlexicon上の_idは
>> >> >> 171になりますが、bufferが壊れているのですかね。
>> >> >>
>> >> >> > select vgram_terms --filter '_key == "9"' --output_columns _id,_key
>> >> >>
>> >> >>
>> >>
>> [[0,1589796398.446896,0.01889300346374512],[[[1],[["_id","UInt32"],["_key","ShortText"]],[171,"9"]]]]
>> >> >>
>> >> >> やはりbufferが壊れるまでを再現できないと難しそうですかね。
>> >> >>
>> >> >> 2020年5月18日(月) 18:12 Naoya Murakami <visio****@gmail*****>:
>> >> >>
>> >> >>> 村上です。
>> >> >>>
>> >> >>> failed to decode / failed to merge chunk / failed to flush a
>> >> bufferが出た場合、
>> >> >>> 静的索引構築でチャンクを作り直すとエラーがでないようになるのですが、
>> >> >>> このエラーはチャンクが壊れていることによるものでしょうか。
>> >> >>>
>> >> >>> たまにマージができなくなってしまうときがあるのでチャンクの再作成を
>> >> >>> しています。
>> >> >>>
>> >> >>> 現状、同じ更新をすれば、必ずfailed to decodeになるデータベースは用意できますが、
>> >> >>> 参考になりますかね。
>> >> >>>
>> >> >>> 最近ようやくバージョンを上げたところで2年前ぐらいのGroongaのコードベースで
>> >> >>> updateしたものも含まれると思います。
>> >> >>>
>> >> >>> [ii][chunk][merge] failed to decode: <vgram_terms.description7>:
>> >> >>> <"9">(2147483819)
>> >> >>> [ii][buffer][merge] failed to merge chunk:
>> <vgram_terms.description7>:
>> >> >>> <"9">(2147483819): chunk:<987>, n-chunks:<9886>
>> >> >>> [ii][update][one] failed to flush a buffer:
>> <vgram_terms.description7>:
>> >> >>> <62108274>:<1>:<178>: term:<"96">, segment:<4917148>, free:<4>,
>> >> >>> required:<16>: [ii][buffer][merge] failed to merge chunk:
>> >> >>> <vgram_terms.description7>: <"9">(2147483819): chunk:<987>,
>> >> n-chunks:<9886>
>> >> >>>
>> >> >>> こうなるまでを再現できなければ、難しいようであれば再作成してしまいます。
>> >> >>>
>> >> >>> 以上、よろしくお願いします。
>> >> >>>
>> >> >>>
>> >>
>> >> _______________________________________________
>> >> groonga-dev mailing list
>> >> groon****@lists*****
>> >> https://lists.osdn.me/mailman/listinfo/groonga-dev
>> >>
>>
>> _______________________________________________
>> groonga-dev mailing list
>> groon****@lists*****
>> https://lists.osdn.me/mailman/listinfo/groonga-dev
>>


groonga-dev メーリングリストの案内
Back to archive index