Naoya Murakami
visio****@gmail*****
2013年 6月 4日 (火) 09:31:34 JST
お世話になっております。村上です。 本件につきまして、以下のように２回ほど、追試しました。 事象発生時のテーブル、クエリは前回の事象発生時と異なっていました。 特定のテーブルに問題があるわけではないようです。 だいたい１０分ぐらいで毎回、mmap cannot alocateが発生します。 当方の環境では、ほぼ１００％再現するようですが、どのようにすれば、 再現環境を構築できるかは特定できかねています。 あとは、spider経由なしで、変わるか等をテストしたいと思いますが、 登録プログラムを修正しないとできないので、時間がかかりそうです。 (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）のスレッド数制限関連の問題なのかなと考えました。 ・参考にしたＵＲＬ http://blog.engineer.adways.net/archives/24844023.html (2)試験2 mysqldのスレッド数を監視しつつ、システム全体のスレッド数制限をあげ、 また、ユーザごとのスレッド数制限をunlimitedにして追試しました。 cat /proc/sys/kernel/threads-max 515016→2060064（4倍に） ulimit -u unlimited しかしながら、試験２でも同様にmmap cannot alocateが発生しました。このときは、mysql -pで通常に接続できました。 mpstat、vmstat、mysqldのスレッド数にあやしいうごきはありませんでした。 ＜試験１＞ ・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 ＜試験２＞ ・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 以上、よろしくお願いします。
