さくらVPSでプロセスが殺される–>間違いでした
さくらのVPS上でCentOS6.10 64bitを使用しているのだが、ここ一ヶ月ほど非常に調子が悪い。特にTomcatがふいにkillされている。
本日のリソース情報も以下のようなものである。
ちょうど、このディスクI/Oが突出している時にプロセスが殺されている。/var/log/messagesを見てみると以下だ。
Oct 21 07:09:48 www8321uj kernel: Out of memory: Kill process 22268 (httpd) score 12 or sacrifice child
Oct 21 07:09:48 www8321uj kernel: Killed process 22268, UID 48, (httpd) total-vm:478428kB, anon-rss:9912kB, file-rss:292kB
Oct 21 15:52:32 www8321uj kernel: Out of memory: Kill process 9559 (httpd) score 14 or sacrifice child
Oct 21 15:52:32 www8321uj kernel: Killed process 9559, UID 48, (httpd) total-vm:593432kB, anon-rss:10036kB, file-rss:272kB
Oct 21 18:51:01 www8321uj kernel: Out of memory: Kill process 13011 (httpd) score 16 or sacrifice child
Oct 21 18:51:01 www8321uj kernel: Killed process 13011, UID 48, (httpd) total-vm:601480kB, anon-rss:18504kB, file-rss:76kB
このときに直前のログを見てみると以下。
Oct 21 18:51:01 www8321uj kernel: httpd invoked oom-killer: gfp_mask=0x200da, order=0, oom_adj=0, oom_score_adj=0
Oct 21 18:51:01 www8321uj kernel: httpd cpuset=/ mems_allowed=0
Oct 21 18:51:01 www8321uj kernel: Pid: 21177, comm: httpd Not tainted 2.6.32-431.5.1.el6.x86_64 #1
Oct 21 18:51:01 www8321uj kernel: Call Trace:
Oct 21 18:51:01 www8321uj kernel: [<ffffffff810d05a1>] ? cpuset_print_task_mems_allowed+0x91/0xb0
Oct 21 18:51:01 www8321uj kernel: [<ffffffff81122950>] ? dump_header+0x90/0x1b0
Oct 21 18:51:01 www8321uj kernel: [<ffffffff8122797c>] ? security_real_capable_noaudit+0x3c/0x70
Oct 21 18:51:01 www8321uj kernel: [<ffffffff81122dd2>] ? oom_kill_process+0x82/0x2a0
Oct 21 18:51:01 www8321uj kernel: [<ffffffff81122d11>] ? select_bad_process+0xe1/0x120
Oct 21 18:51:01 www8321uj kernel: [<ffffffff81123210>] ? out_of_memory+0x220/0x3c0
Oct 21 18:51:01 www8321uj kernel: [<ffffffff8112fb2c>] ? __alloc_pages_nodemask+0x8ac/0x8d0
Oct 21 18:51:01 www8321uj kernel: [<ffffffff81167b8a>] ? alloc_pages_vma+0x9a/0x150
Oct 21 18:51:01 www8321uj kernel: [<ffffffff8115b862>] ? read_swap_cache_async+0xf2/0x160
Oct 21 18:51:01 www8321uj kernel: [<ffffffff8115c389>] ? valid_swaphandles+0x69/0x150
Oct 21 18:51:01 www8321uj kernel: [<ffffffff8115b957>] ? swapin_readahead+0x87/0xc0
Oct 21 18:51:01 www8321uj kernel: [<ffffffff8114ac2d>] ? handle_pte_fault+0x6dd/0xb00
Oct 21 18:51:01 www8321uj kernel: [<ffffffff8112ff1f>] ? free_hot_page+0x2f/0x60
Oct 21 18:51:01 www8321uj kernel: [<ffffffff8114b27a>] ? handle_mm_fault+0x22a/0x300
Oct 21 18:51:01 www8321uj kernel: [<ffffffff8104a8d8>] ? __do_page_fault+0x138/0x480
Oct 21 18:51:01 www8321uj kernel: [<ffffffff81282561>] ? cpumask_any_but+0x31/0x50
Oct 21 18:51:01 www8321uj kernel: [<ffffffff81150230>] ? unmap_region+0x110/0x130
Oct 21 18:51:01 www8321uj kernel: [<ffffffff8114e3be>] ? remove_vma+0x6e/0x90
Oct 21 18:51:01 www8321uj kernel: [<ffffffff8152d76e>] ? do_page_fault+0x3e/0xa0
Oct 21 18:51:01 www8321uj kernel: [<ffffffff8152ab25>] ? page_fault+0x25/0x30
Oct 21 18:51:01 www8321uj kernel: Mem-Info:
Oct 21 18:51:01 www8321uj kernel: Node 0 DMA per-cpu:
Oct 21 18:51:01 www8321uj kernel: CPU 0: hi: 0, btch: 1 usd: 0
Oct 21 18:51:01 www8321uj kernel: CPU 1: hi: 0, btch: 1 usd: 0
Oct 21 18:51:01 www8321uj kernel: CPU 2: hi: 0, btch: 1 usd: 0
Oct 21 18:51:01 www8321uj kernel: Node 0 DMA32 per-cpu:
Oct 21 18:51:01 www8321uj kernel: CPU 0: hi: 186, btch: 31 usd: 160
Oct 21 18:51:01 www8321uj kernel: CPU 1: hi: 186, btch: 31 usd: 170
Oct 21 18:51:01 www8321uj kernel: CPU 2: hi: 186, btch: 31 usd: 144
Oct 21 18:51:01 www8321uj kernel: active_anon:337432 inactive_anon:113283 isolated_anon:1056
Oct 21 18:51:01 www8321uj kernel: active_file:38 inactive_file:79 isolated_file:4
Oct 21 18:51:01 www8321uj kernel: unevictable:0 dirty:0 writeback:92 unstable:0
Oct 21 18:51:01 www8321uj kernel: free:14817 slab_reclaimable:3921 slab_unreclaimable:11709
Oct 21 18:51:01 www8321uj kernel: mapped:71 shmem:13 pagetables:22691 bounce:0
Oct 21 18:51:01 www8321uj kernel: Node 0 DMA free:8436kB min:332kB low:412kB high:496kB active_anon:2604kB inactive_anon:4024kB active_file:28kB inactive_file:104kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15348kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:16kB slab_unreclaimable:76kB kernel_stack:0kB pagetables:240kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:480 all_unreclaimable? no
Oct 21 18:51:01 www8321uj kernel: lowmem_reserve[]: 0 2004 2004 2004
Oct 21 18:51:01 www8321uj kernel: Node 0 DMA32 free:50832kB min:44720kB low:55900kB high:67080kB active_anon:1347124kB inactive_anon:449108kB active_file:124kB inactive_file:296kB unevictable:0kB isolated(anon):4096kB isolated(file):0kB present:2052308kB mlocked:0kB dirty:0kB writeback:392kB mapped:288kB shmem:52kB slab_reclaimable:15668kB slab_unreclaimable:46760kB kernel_stack:2272kB pagetables:90524kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:1312 all_unreclaimable? no
Oct 21 18:51:01 www8321uj kernel: lowmem_reserve[]: 0 0 0 0
Oct 21 18:51:01 www8321uj kernel: Node 0 DMA: 14*4kB 17*8kB 8*16kB 4*32kB 5*64kB 2*128kB 1*256kB 4*512kB 3*1024kB 1*2048kB 0*4096kB = 8448kB
Oct 21 18:51:01 www8321uj kernel: Node 0 DMA32: 3018*4kB 2417*8kB 950*16kB 6*32kB 1*64kB 1*128kB 1*256kB 1*512kB 1*1024kB 1*2048kB 0*4096kB = 50832kB
Oct 21 18:51:01 www8321uj kernel: 64202 total pagecache pages
Oct 21 18:51:01 www8321uj kernel: 63923 pages in swap cache
Oct 21 18:51:01 www8321uj kernel: Swap cache stats: add 51621858, delete 51557935, find 17263592/22172199
Oct 21 18:51:01 www8321uj kernel: Free swap = 0kB
Oct 21 18:51:01 www8321uj kernel: Total swap = 2097144kB
Oct 21 18:51:01 www8321uj kernel: 524284 pages RAM
Oct 21 18:51:01 www8321uj kernel: 10700 pages reserved
Oct 21 18:51:01 www8321uj kernel: 24026 pages shared
Oct 21 18:51:01 www8321uj kernel: 491062 pages non-shared
Oct 21 18:51:01 www8321uj kernel: [ pid ] uid tgid total_vm rss cpu oom_adj oom_score_adj name
Oct 21 18:51:01 www8321uj kernel: [ 406] 0 406 2722 1 0 -17 -1000 udevd
Oct 21 18:51:01 www8321uj kernel: [ 1853] 0 1853 4563 26 0 0 0 irqbalance
Oct 21 18:51:01 www8321uj kernel: [ 1864] 0 1864 6114 2 1 0 0 fbguard
Oct 21 18:51:01 www8321uj kernel: [ 1865] 0 1865 30428 16 1 0 0 fbserver
Oct 21 18:51:01 www8321uj kernel: [ 1920] 0 1920 1020 1 1 0 0 acpid
Oct 21 18:51:01 www8321uj kernel: [ 1963] 0 1963 5429 2 2 0 0 xinetd
（略）
Oct 21 18:51:01 www8321uj kernel: [21271] 48 21271 109658 982 1 0 0 httpd
Oct 21 18:51:01 www8321uj kernel: [21272] 48 21272 12975 781 1 0 0 python
Oct 21 18:51:01 www8321uj kernel: [21273] 48 21273 109697 1206 1 0 0 httpd
Oct 21 18:51:01 www8321uj kernel: [21284] 48 21284 12975 781 0 0 0 python
Oct 21 18:51:01 www8321uj kernel: [21285] 48 21285 109503 259 1 0 0 httpd
Oct 21 18:51:01 www8321uj kernel: [21286] 48 21286 134732 2374 0 0 0 httpd
Oct 21 18:51:01 www8321uj kernel: Out of memory: Kill process 13011 (httpd) score 16 or sacrifice child
Oct 21 18:51:01 www8321uj kernel: Killed process 13011, UID 48, (httpd) total-vm:601480kB, anon-rss:18504kB, file-rss:76kB
この「Not tainted」という不審なメッセージを調べてみた。どうもこの部分でカーネルがパニックを起こしているようだ。それがこの異常なディスクI/Oの原因なのだろうか？
CentOS 6.3 – Kernel Panicという書き込みがある。
つまり、いろいろyum updateしたにもかかわらずOSを再起動せず、カーネルが古いままというのがいけなかったのだろうか？
とりあえず再起動して新たなバージョンのカーネルで動作させ、様子を見ることにする。
–> 二日経過したが、問題無いようだ。要するに、yum updateで一切合切新しくしたのに、再起動しなかったためにカーネルとの間に齟齬が生じ、それが上記のようなカーネルパニック状態を引き起こしていたようだ。
–> やはり問題が起こった。これまでと同様にTomcatなどのプロセスが殺されてしまう。
解決したと思われる方法
結局のところ原因はこうらしい。上記エラーで見られる通り、問題はhttpdである。httpdのプロセスが多すぎるためにメモリ不足に陥り、カーネル側はメモリを確保するために何らかのプロセスを殺してしまうだが、そこで選ばれるのが、なぜかhttpdのプロセスではなく、Tomcat等のJavaのプロセスになってしまう。
そのため、httpdの方は何ら問題無く動作しているように見え、一方でTomcat等のJavaプロセスが落ちてしまう。
解決法としては、httpdの同時接続数を制限した。以下で、コメントアウトしているのがデフォルトの値である。
<IfModule prefork.c>
StartServers 8
MinSpareServers 5
MaxSpareServers 20
#ServerLimit 256
#MaxClients 256
ServerLimit 25
MaxClients 25
MaxRequestsPerChild 4000
</IfModule>
※その後の状況についてはApacheのメモリ消費を抑える(prefork)を参照してほしい。