大川敬臣
yoshi****@kccs*****
2018年 5月 18日 (金) 12:30:39 JST
各務様 こんにちは、ご連絡ありがとうございます。 再現テストで1度だけ発生したのですが、その後も何度かトライしているのですが、再発しない状況です。 しかも、再発した1回もmysqldumpですと時間がかかるので、「FLUSH TABLES；」でテストした際に 発生しただけです。 ログですが、発生当時のログは私の手元にないので共有できないのですが、 再現テストで再発した際の MySQLのログとmessagesは以下となります。 （groonga.logは取っておりませんでした。。。 後ほど取得できましたら、追加で共有させていただきます。） 以上、よろしくお願いいたします。 ===MySQL log======== [Thu May 17 15:25:00.892 2018] 15:25:00 [user ＠ test001 ~]$ tail -F /var/log/mysql/mysql.err [Thu May 17 15:50:52.202 2018] 06:50:52 UTC - mysqld got signal 11 ; [Thu May 17 15:50:52.202 2018] This could be because you hit a bug. It is also possible that this binary [Thu May 17 15:50:52.202 2018] or one of the libraries it was linked against is corrupt, improperly built, [Thu May 17 15:50:52.202 2018] or misconfigured. This error can also be caused by malfunctioning hardware. [Thu May 17 15:50:52.202 2018] We will try our best to scrape up some info that will hopefully help [Thu May 17 15:50:52.202 2018] diagnose the problem, but since we have already crashed, [Thu May 17 15:50:52.202 2018] something is definitely wrong and this may fail. [Thu May 17 15:50:52.202 2018] [Thu May 17 15:50:52.202 2018] key_buffer_size=8388608 [Thu May 17 15:50:52.202 2018] read_buffer_size=524288 [Thu May 17 15:50:52.202 2018] max_used_connections=12 [Thu May 17 15:50:52.202 2018] max_threads=6000 [Thu May 17 15:50:52.202 2018] thread_count=6 [Thu May 17 15:50:52.202 2018] connection_count=6 [Thu May 17 15:50:52.202 2018] It is possible that mysqld could use up to [Thu May 17 15:50:52.202 2018] key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 9305332 K bytes of memory [Thu May 17 15:50:52.202 2018] Hope that's ok; if not, decrease some variables in the equation. [Thu May 17 15:50:52.202 2018] [Thu May 17 15:50:52.202 2018] Thread pointer: 0x1013db100 [Thu May 17 15:50:52.202 2018] Attempting backtrace. You can use the following information to find out [Thu May 17 15:50:52.202 2018] where mysqld died. If you see no messages after this, something went [Thu May 17 15:50:52.202 2018] terribly wrong... [Thu May 17 15:50:52.234 2018] stack_bottom = 7f8cfa2d5e18 thread_stack 0x40000 [Thu May 17 15:50:52.234 2018] /usr/sbin/mysqld(my_print_stacktrace+0x35)[0x8f85e5] [Thu May 17 15:50:52.234 2018] /usr/sbin/mysqld(handle_fatal_signal+0x4a4)[0x68f2e4] [Thu May 17 15:50:52.234 2018] /lib64/libpthread.so.0[0x3928e0f500] [Thu May 17 15:50:52.234 2018] /usr/lib64/libgroonga.so.0(grn_expr_add_var+0x1ac)[0x32532607bc] [Thu May 17 15:50:52.234 2018] /usr/lib64/libgroonga.so.0(grn_proc_create+0x578)[0x3253239468] [Thu May 17 15:50:52.234 2018] /usr/lib64/libgroonga.so.0(grn_normalizer_register+0x6f)[0x32533720bf] [Thu May 17 15:50:52.234 2018] /usr/lib64/groonga/plugins/normalizers/mysql.so(grn_plugin_impl_register+0x21)[0x7f8cc2de5481] [Thu May 17 15:50:52.234 2018] /usr/lib64/libgroonga.so.0(grn_plugin_register_by_path+0x354)[0x325338a294] [Thu May 17 15:50:52.234 2018] /usr/lib64/libgroonga.so.0(grn_plugin_register+0x4f)[0x325338a30f] [Thu May 17 15:50:52.234 2018] /usr/lib64/mysql/plugin/ha_mroonga.so(_ZN10ha_mroonga20ensure_database_openEPKc+0x185)[0x7fb62cbcfcf5] [Thu May 17 15:50:52.234 2018] /usr/lib64/mysql/plugin/ha_mroonga.so(_ZN10ha_mroonga12wrapper_openEPKcij+0x34)[0x7fb62cbd0744] [Thu May 17 15:50:52.234 2018] /usr/lib64/mysql/plugin/ha_mroonga.so(_ZN10ha_mroonga4openEPKcij+0xaa)[0x7fb62cbd0b2a] [Thu May 17 15:50:52.234 2018] /usr/sbin/mysqld(_ZN7handler7ha_openEP5TABLEPKcii+0x3e)[0x5d5b4e] [Thu May 17 15:50:52.234 2018] /usr/sbin/mysqld(_Z21open_table_from_shareP3THDP11TABLE_SHAREPKcjjjP5TABLEb+0x624)[0x7919f4] [Thu May 17 15:50:52.237 2018] /usr/sbin/mysqld(_Z10open_tableP3THDP10TABLE_LISTP18Open_table_context+0x1eb)[0x6c52eb] [Thu May 17 15:50:52.237 2018] /usr/sbin/mysqld(_Z11open_tablesP3THDPP10TABLE_LISTPjjP19Prelocking_strategy+0xcaa)[0x6c7aba] [Thu May 17 15:50:52.237 2018] /usr/sbin/mysqld(_Z30open_normal_and_derived_tablesP3THDP10TABLE_LISTj+0x4f)[0x6c7bdf] [Thu May 17 15:50:52.283 2018] /usr/sbin/mysqld[0x7069e1] [Thu May 17 15:50:52.283 2018] /usr/sbin/mysqld(_Z21mysql_execute_commandP3THD+0x117e)[0x7090be] [Thu May 17 15:50:52.283 2018] /usr/sbin/mysqld(_Z11mysql_parseP3THDPcjP12Parser_state+0x32f)[0x70cc0f] [Thu May 17 15:50:52.283 2018] /usr/sbin/mysqld(_Z16dispatch_command19enum_server_commandP3THDPcj+0xe28)[0x70db28] [Thu May 17 15:50:52.283 2018] /usr/sbin/mysqld(_Z24do_handle_one_connectionP3THD+0xcf)[0x6db6cf] [Thu May 17 15:50:52.283 2018] /usr/sbin/mysqld(handle_one_connection+0x47)[0x6db7f7] [Thu May 17 15:50:52.283 2018] /usr/sbin/mysqld(pfs_spawn_thread+0x139)[0x97a0a9] [Thu May 17 15:50:52.283 2018] /lib64/libpthread.so.0[0x3928e07851] [Thu May 17 15:50:52.283 2018] /lib64/libc.so.6(clone+0x6d)[0x3928ae890d] [Thu May 17 15:50:52.283 2018] [Thu May 17 15:50:52.283 2018] Trying to get some variables. [Thu May 17 15:50:52.283 2018] Some pointers may be invalid and cause the dump to abort. [Thu May 17 15:50:52.283 2018] Query (7f8c3c0e1790): is an invalid pointer [Thu May 17 15:50:52.283 2018] Connection ID (thread ID): 63749 [Thu May 17 15:50:52.283 2018] Status: NOT_KILLED [Thu May 17 15:50:52.283 2018] [Thu May 17 15:50:52.283 2018] The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains [Thu May 17 15:50:52.283 2018] information that should help you find out what is causing the crash. [Thu May 17 15:50:52.540 2018] 180517 15:50:52 mysqld_safe Number of processes running now: 0 [Thu May 17 15:50:52.540 2018] 180517 15:50:52 mysqld_safe mysqld restarted ======================================================================= ===messages======== [Thu May 17 15:50:02.149 2018] May 17 15:50:02 test001 xinetd[4620]: START: shell pid=10341 from=::ffff:10.181.192.1 [Thu May 17 15:50:02.394 2018] May 17 15:50:02 test001 cibadmin: [10428]: info: Invoked: cibadmin -Q [Thu May 17 15:50:02.394 2018] May 17 15:50:02 test001 cibadmin: [10444]: info: Invoked: cibadmin --query --xpath //crm_config//nvpair[@name='cluster_name'] [Thu May 17 15:50:02.394 2018] May 17 15:50:02 test001 cibadmin: [10449]: info: Invoked: cibadmin --query --xpath //primitive[@id='res_IPaddr2_cluster_ip'][@type='IPaddr2']/instance_attributes/nvpair[@name='ip'] [Thu May 17 15:50:02.394 2018] May 17 15:50:02 test001 xinetd[4620]: EXIT: shell status=0 pid=10341 duration=0(sec) [Thu May 17 15:50:02.646 2018] May 17 15:50:02 test001 xinetd[4620]: START: shell pid=10496 from=::ffff:10.181.192.1 [Thu May 17 15:50:02.896 2018] May 17 15:50:02 test001 cibadmin: [10559]: info: Invoked: cibadmin -Q [Thu May 17 15:50:02.896 2018] May 17 15:50:02 test001 cibadmin: [10578]: info: Invoked: cibadmin --query --xpath //crm_config//nvpair[@name='cluster_name'] [Thu May 17 15:50:02.896 2018] May 17 15:50:02 test001 cibadmin: [10581]: info: Invoked: cibadmin --query --xpath //primitive[@id='res_IPaddr2_cluster_ip'][@type='IPaddr2']/instance_attributes/nvpair[@name='ip'] [Thu May 17 15:50:02.896 2018] May 17 15:50:02 test001 xinetd[4620]: EXIT: shell status=0 pid=10496 duration=0(sec) [Thu May 17 15:50:04.606 2018] May 17 15:50:04 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:50:07.602 2018] May 17 15:50:07 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:50:10.639 2018] May 17 15:50:10 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:50:13.607 2018] May 17 15:50:13 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:50:16.630 2018] May 17 15:50:16 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:50:19.613 2018] May 17 15:50:19 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:50:20.602 2018] May 17 15:50:20 test001 cibadmin: [16931]: info: Invoked: cibadmin -Q [Thu May 17 15:50:20.844 2018] May 17 15:50:20 test001 cibadmin: [16953]: info: Invoked: cibadmin --query --xpath //crm_config//nvpair[@name='cluster_name'] [Thu May 17 15:50:20.844 2018] May 17 15:50:20 test001 cibadmin: [16957]: info: Invoked: cibadmin --query --xpath //primitive[@id='res_IPaddr2_cluster_ip'][@type='IPaddr2']/instance_attributes/nvpair[@name='ip'] [Thu May 17 15:50:22.620 2018] May 17 15:50:22 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:50:25.619 2018] May 17 15:50:25 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:50:28.623 2018] May 17 15:50:28 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:50:31.625 2018] May 17 15:50:31 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:50:35.406 2018] May 17 15:50:34 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:50:37.628 2018] May 17 15:50:37 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:50:40.634 2018] May 17 15:50:40 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:50:43.645 2018] May 17 15:50:43 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:50:46.642 2018] May 17 15:50:46 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:50:49.672 2018] May 17 15:50:49 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:50:52.649 2018] May 17 15:50:52 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:50:55.648 2018] May 17 15:50:55 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:50:58.651 2018] May 17 15:50:58 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:51:01.656 2018] May 17 15:51:01 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:51:02.335 2018] May 17 15:51:02 test001 xinetd[4620]: START: shell pid=30903 from=::ffff:10.181.192.1 [Thu May 17 15:51:02.577 2018] May 17 15:51:02 test001 cibadmin: [30961]: info: Invoked: cibadmin -Q [Thu May 17 15:51:02.577 2018] May 17 15:51:02 test001 cibadmin: [30988]: info: Invoked: cibadmin --query --xpath //crm_config//nvpair[@name='cluster_name'] [Thu May 17 15:51:02.577 2018] May 17 15:51:02 test001 cibadmin: [30994]: info: Invoked: cibadmin --query --xpath //primitive[@id='res_IPaddr2_cluster_ip'][@type='IPaddr2']/instance_attributes/nvpair[@name='ip'] [Thu May 17 15:51:02.577 2018] May 17 15:51:02 test001 xinetd[4620]: EXIT: shell status=0 pid=30903 duration=0(sec) [Thu May 17 15:51:02.868 2018] May 17 15:51:02 test001 xinetd[4620]: START: shell pid=31026 from=::ffff:10.181.192.1 [Thu May 17 15:51:02.868 2018] May 17 15:51:02 test001 cibadmin: [31086]: info: Invoked: cibadmin -Q [Thu May 17 15:51:02.868 2018] May 17 15:51:02 test001 cibadmin: [31093]: info: Invoked: cibadmin --query --xpath //crm_config//nvpair[@name='cluster_name'] [Thu May 17 15:51:02.868 2018] May 17 15:51:02 test001 cibadmin: [31095]: info: Invoked: cibadmin --query --xpath //primitive[@id='res_IPaddr2_cluster_ip'][@type='IPaddr2']/instance_attributes/nvpair[@name='ip'] [Thu May 17 15:51:02.868 2018] May 17 15:51:02 test001 xinetd[4620]: EXIT: shell status=0 pid=31026 duration=0(sec) [Thu May 17 15:51:04.669 2018] May 17 15:51:04 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:51:07.661 2018] May 17 15:51:07 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:51:10.459 2018] May 17 15:51:10 test001 cibadmin: [1252]: info: Invoked: cibadmin -Q [Thu May 17 15:51:10.709 2018] May 17 15:51:10 test001 cibadmin: [1273]: info: Invoked: cibadmin --query --xpath //crm_config//nvpair[@name='cluster_name'] [Thu May 17 15:51:10.709 2018] May 17 15:51:10 test001 cibadmin: [1276]: info: Invoked: cibadmin --query --xpath //primitive[@id='res_IPaddr2_cluster_ip'][@type='IPaddr2']/instance_attributes/nvpair[@name='ip'] [Thu May 17 15:51:10.709 2018] May 17 15:51:10 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:51:13.671 2018] May 17 15:51:13 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:51:16.678 2018] May 17 15:51:16 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:51:19.688 2018] May 17 15:51:19 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:51:22.675 2018] May 17 15:51:22 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:51:25.680 2018] May 17 15:51:25 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:51:28.683 2018] May 17 15:51:28 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:51:31.686 2018] May 17 15:51:31 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:51:34.693 2018] May 17 15:51:34 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:51:37.695 2018] May 17 15:51:37 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:51:40.695 2018] May 17 15:51:40 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:51:43.705 2018] May 17 15:51:43 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:51:46.701 2018] May 17 15:51:46 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager [Thu May 17 15:51:49.703 2018] May 17 15:51:49 test001 snmpd[4612]: refused smux peer: oid SNMPv2-SMI::enterprises.674.10892.1, descr Systems Management SNMP MIB Plug-in Manager ================================================================== 2018年5月17日 20:23 各務洋 <kagam****@pyrol*****>: > 大川様。 > 各務と申します。 > > mysqldump での クラッシュですと、毎回発生しないようですと、再現は大変な気がします。 > > クラッシュが発生した際のログ、 > > /var/log/message > /var/lib/mysql/groonga.log > /var/log/mysqld.log > > あたりを記述いただければ、何か知見が出てくるかもしれないです。 > > 個人的には CentOS 5の頃の設定、 vm.swappiness = 0 を CentOS 6 に適用していて > よくクラッシュしていました。 > > 過渡的な状況でしたら、クラッシュしにくくなる緩和策を求めるのも手かもしれないです。 > いかがでしょうか？ > > 2018年5月17日 17:32 大川敬臣 <yoshi****@kccs*****>: > > お世話になっております。 > > 大川と申します。 > > > > 以下の環境でのMySQL Databaseサーバで質問させてください。 > > > > RHEL：6.4 > > MySQL：5.6.11 > > Mroonga：3.0.3 > > > > 上記の環境でmysqldumpを実行したタイミングでMySQLが再起動する事象が発生しました。 > > 当方では、以下のバグに該当していると想定しております。 > > （Oracleサポートに問い合わせしたところ、Mroongaストレージエンジンでクラッシュが発生したため、 > MySQLが再起動したと回答を頂いております。） > > > > 【Bug #2098】 ストレージエンジンMroonga時にmysqldumpするとmysqldが落ちる > > http://redmine.groonga.org/issues/2098 > > > > 実際に発生した環境は商用の環境なのですが、顧客説明のため、テスト環境で再現試験を行っております。 > > しかし、何度mysqldumpを実行しても再現させることができません。 > > 実際にMySQLの再起動が発生したコマンドは以下となります。 > > > >>mysqldump --login-path=root --single-transaction --max-allowed-packet=1G > >> --events --routines --flush-logs --master-data=2 --flush-privileges > >> --all-databases > /data/db_mkt_delivery.sql & > > > > 最終的には上記コマンドでは無く、オプションを変えてMroonga ストレージエンジンを含まないDBのみdump出力するように > > 変更する予定なのですが、その変更が効果があるかを確認したく、ます、再現をさせている状況でございます。 > > > > 上記のmysqldumpで再現させるアイデアがあればご教示いただきたく質問させていただきました。 > > > > 事象が上記のバグではないんじゃないか？と言った意見もございましたら、ご教示くださいますようお願いいたします。 > > > > 皆様、どうぞよろしくお願いいたします。 > > > > _______________________________________________ > > 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 > -------------- next part -------------- HTML$B$NE:IU%U%!%$%k$rJ]4I$7$^$7$?(B... URL: https://lists.osdn.me/mailman/archives/groonga-dev/attachments/20180518/b0dfe852/attachment-0001.htm
