Naoya Murakami
visio****@gmail*****
2013年 6月 4日 (火) 21:35:29 JST
お世話になっております。村上です。 本件につきまして、自己解決いたしました。 shmax等、メモリ関連のカーネルパラメータを適宜増加させて、何度かテストをしました。 以下の事案を参考に、vm.max_map_countの値を10倍にしてみたところ、 本事象が発生しなくなりました。 (以下の事案では、vm.max_map_countで解決したわけではないようですが。) http://redmine.groonga.org/issues/689 再度、vm.max_map_countの値をもとに戻し、再テストを行ったところ、事象が再発しましたので、 このパラメータの変更が有効だったと思われます。 当方のパラメータ調整ミスでした。大変失礼いたしました。 以上です。 2013年6月4日 9:31 Naoya Murakami <visio****@gmail*****>: > お世話になっております。村上です。 > > 本件につきまして、以下のように2回ほど、追試しました。 > > 事象発生時のテーブル、クエリは前回の事象発生時と異なっていました。 > 特定のテーブルに問題があるわけではないようです。 > だいたい10分ぐらいで毎回、mmap cannot alocateが発生します。 > > 当方の環境では、ほぼ100%再現するようですが、どのようにすれば、 > 再現環境を構築できるかは特定できかねています。 > > あとは、spider経由なしで、変わるか等をテストしたいと思いますが、 > 登録プログラムを修正しないとできないので、時間がかかりそうです。 > > > (1) 試験1 > 1回目は、まず、メモリ量等を監視しつつ、事象を再現させました。 > vmstatであやしいうごきはみられませんでしたが、事象発生時にmysql -p で接続しにいくと、 > Can't create a new thread (errno 11); if you are not out of available > memory, you can consult the manual for a possible OS-dependent bug > のメッセージが発生し、接続できませんでした。 > > そこで、OS(CentOS6)のスレッド数制限関連の問題なのかなと考えました。 > ・参考にしたURL > http://blog.engineer.adways.net/archives/24844023.html > > (2)試験2 > mysqldのスレッド数を監視しつつ、システム全体のスレッド数制限をあげ、 > また、ユーザごとのスレッド数制限をunlimitedにして追試しました。 > > cat /proc/sys/kernel/threads-max > 515016→2060064(4倍に) > ulimit -u unlimited > > しかしながら、試験2でも同様にmmap cannot alocateが発生しました。このときは、mysql -pで通常に接続できました。 > mpstat、vmstat、mysqldのスレッド数にあやしいうごきはありませんでした。 > > <試験1> > ・groonga.log > 2013-06-04 04:28:41.222563|n|0cbb3700|split (5955) encsize=393922 > 2013-06-04 04:28:42.062654|A|0cbb3700|mmap(4194304,735,838860800)=Cannot > allocate memory <13047246848> > 2013-06-04 04:28:42.066369|A|0cbb3700|/usr/lib64/libgroonga.so.0() > [0x35dc72e5fb] > > ・vmstat > 2013/06/04 04:28:34 1 0 164 226788 72532 29599988 0 0 38644 > 138036 8132 1316 11 2 86 1 0 > 2013/06/04 04:28:36 2 0 164 224568 72528 29593844 0 0 > 6628 0 3131 3560 13 1 86 0 0 > 2013/06/04 04:28:38 1 0 164 232808 72560 29572364 0 0 33360 > 1140 3853 3352 12 1 86 1 0 > 2013/06/04 04:28:40 1 0 164 227704 72576 29568144 0 0 5240 > 12 3455 2890 13 0 86 0 0 > 2013/06/04 04:28:42 1 0 164 229988 72576 29559820 0 0 > 6048 0 2749 2444 13 1 86 0 0 > 2013/06/04 04:28:44 1 0 164 234100 72612 29554636 0 0 9668 > 99120 4911 2466 13 1 86 1 0 > 2013/06/04 04:28:46 1 0 164 224052 72660 29564580 0 0 > 3856 0 2565 2054 13 0 87 0 0 > 2013/06/04 04:28:48 1 0 164 227460 72660 29572512 0 0 > 3628 0 2555 2022 12 1 87 1 0 > > ・mpstat -P ALL > > 04時28分38秒 CPU %usr %nice %sys %iowait %irq %soft %steal > %guest %idle > 04時28分41秒 all 12.01 0.00 0.83 0.75 0.00 0.08 0.00 > 0.00 86.32 > 04時28分41秒 0 76.25 0.00 4.01 5.69 0.00 0.33 0.00 > 0.00 13.71 > 04時28分41秒 1 1.66 0.00 0.33 0.00 0.00 0.00 0.00 > 0.00 98.01 > 04時28分41秒 2 1.33 0.00 0.33 0.00 0.00 0.00 0.00 > 0.00 98.33 > 04時28分41秒 3 1.67 0.00 0.00 0.33 0.00 0.00 0.00 > 0.00 98.00 > 04時28分41秒 4 12.71 0.00 0.67 0.00 0.00 0.33 0.00 > 0.00 86.29 > 04時28分41秒 5 1.33 0.00 0.33 0.00 0.00 0.00 0.00 > 0.00 98.33 > 04時28分41秒 6 1.00 0.00 0.33 0.00 0.00 0.00 0.00 > 0.00 98.66 > 04時28分41秒 7 0.67 0.00 0.67 0.00 0.00 0.00 0.00 > 0.00 98.67 > > 04時28分41秒 CPU %usr %nice %sys %iowait %irq %soft %steal > %guest %idle > 04時28分44秒 all 12.43 0.00 0.50 0.75 0.00 0.13 0.00 > 0.00 86.19 > 04時28分44秒 0 82.09 0.00 1.69 5.07 0.00 1.01 0.00 > 0.00 10.14 > 04時28分44秒 1 1.00 0.00 0.33 0.00 0.00 0.00 0.00 > 0.00 98.67 > 04時28分44秒 2 1.33 0.00 0.00 0.00 0.00 0.00 0.00 > 0.00 98.67 > 04時28分44秒 3 4.68 0.00 0.00 0.00 0.00 0.00 0.00 > 0.00 95.32 > 04時28分44秒 4 7.95 0.00 1.66 0.99 0.00 0.33 0.00 > 0.00 89.07 > 04時28分44秒 5 1.00 0.00 0.00 0.00 0.00 0.00 0.00 > 0.00 99.00 > 04時28分44秒 6 1.00 0.00 0.00 0.00 0.00 0.00 0.00 > 0.00 99.00 > 04時28分44秒 7 0.67 0.00 0.00 0.00 0.00 0.00 0.00 > 0.00 99.33 > > > <試験2> > ・groonga.log > 2013-06-04 08:19:12.249306|n|4e86e700|split (1997) encsize=396740 > 2013-06-04 08:19:34.835218|A|4e86e700|mmap(4194304,551,432017408)=Cannot > allocate memory <13036498944> > 2013-06-04 08:19:34.838731|A|4e86e700|/usr/lib64/libgroonga.so.0() > [0x35dc72e5fb] > > ・vmstat.log > 2013/06/04 08:19:26 0 1 256 528500 74532 29249884 0 0 > 45752 0 2793 1529 11 1 87 1 0 > 2013/06/04 08:19:28 1 0 256 458012 74544 29313972 0 0 38296 > 488 3018 2483 9 3 87 1 0 > 2013/06/04 08:19:30 1 0 256 425560 74544 29343440 0 0 > 13912 0 4017 4528 12 1 86 1 0 > 2013/06/04 08:19:32 1 0 256 342504 74544 29395016 0 0 > 35316 0 4188 4685 12 1 86 1 0 > 2013/06/04 08:19:34 1 0 256 333636 74552 29419520 0 0 > 4672 0 2532 1100 9 0 88 3 0 > 2013/06/04 08:19:36 1 0 256 295404 74552 29454484 0 0 > 14724 0 2865 2615 12 1 87 1 0 > 2013/06/04 08:19:38 3 0 256 275844 74560 29473376 0 0 10456 > 424 3026 1476 12 0 87 1 0 > 2013/06/04 08:19:40 1 0 256 248436 74560 29500976 0 0 > 12584 0 3123 2901 13 1 86 1 0 > 2013/06/04 08:19:42 1 0 256 220436 74560 29526152 0 0 > 18296 0 3392 2698 11 1 87 1 0 > > ・mysqld スレッド数 > > 2013/06/04 08:19:32 > Variable_name Value > Threads_cached 1 > Threads_connected 2 > Threads_created 3 > Threads_running 1 > mysqld pid num 7 ( ps -efL | grep -e mysqld -e PID | grep -v grep | wc > -lの結果) > 2013/06/04 08:19:35 > Variable_name Value > Threads_cached 1 > Threads_connected 2 > Threads_created 3 > Threads_running 1 > mysqld pid num 7 > > > ・mpstat > > 08時19分30秒 CPU %usr %nice %sys %iowait %irq %soft %steal > %guest %idle > 08時19分33秒 all 11.54 0.00 0.96 1.04 0.00 0.12 0.00 > 0.00 86.33 > 08時19分33秒 0 73.33 0.00 5.67 8.33 0.00 0.67 0.00 > 0.00 12.00 > 08時19分33秒 1 8.64 0.00 0.33 0.00 0.00 0.00 0.00 > 0.00 91.03 > 08時19分33秒 2 1.00 0.00 0.00 0.00 0.00 0.00 0.00 > 0.00 99.00 > 08時19分33秒 3 1.00 0.00 0.33 0.00 0.00 0.00 0.00 > 0.00 98.66 > 08時19分33秒 4 4.35 0.00 1.00 0.00 0.00 0.00 0.00 > 0.00 94.65 > 08時19分33秒 5 1.34 0.00 0.00 0.00 0.00 0.00 0.00 > 0.00 98.66 > 08時19分33秒 6 1.00 0.00 0.33 0.00 0.00 0.00 0.00 > 0.00 98.67 > 08時19分33秒 7 1.00 0.00 0.33 0.00 0.00 0.00 0.00 > 0.00 98.67 > > 08時19分33秒 CPU %usr %nice %sys %iowait %irq %soft %steal > %guest %idle > 08時19分36秒 all 10.52 0.00 1.13 1.63 0.00 0.08 0.00 > 0.00 86.64 > 08時19分36秒 0 75.00 0.00 4.05 12.84 0.00 0.34 0.00 > 0.00 7.77 > 08時19分36秒 1 1.33 0.00 1.00 0.00 0.00 0.00 0.00 > 0.00 97.67 > 08時19分36秒 2 1.00 0.00 0.33 0.00 0.00 0.00 0.00 > 0.00 98.67 > 08時19分36秒 3 1.33 0.00 0.33 0.00 0.00 0.00 0.00 > 0.00 98.34 > 08時19分36秒 4 3.33 0.00 0.67 0.00 0.00 0.33 0.00 > 0.00 95.67 > 08時19分36秒 5 1.00 0.00 2.99 0.00 0.00 0.00 0.00 > 0.00 96.01 > 08時19分36秒 6 1.34 0.00 0.00 0.00 0.00 0.00 0.00 > 0.00 98.66 > 08時19分36秒 7 1.00 0.00 0.00 0.00 0.00 0.00 0.00 > 0.00 99.00 > > > 以上、よろしくお願いします。 > >