У нас есть веб-приложение, которое работает в AWS Elastic Beanstalk и использует Java в качестве бэкэнда. Периодически происходит сбой одного сервера приложений за балансировщиком нагрузки из-за того, что процессор используется на 100%. После некоторого анализа у меня есть основания полагать, что основная ОС может сыграть роль в этой проблеме.
Вот фрагмент из файла / var / log / messages с точкой, где ядро ловит ошибку:
Jan 3 22:50:11 ip-10-220-46-44 kernel: [22649903.665305] ------------[ cut here ]------------
Jan 3 22:50:11 ip-10-220-46-44 kernel: [22649903.676120] WARNING: CPU: 0 PID: 12578 at fs/dcache.c:361 d_shrink_del+0x71/0x80()
Jan 3 22:50:11 ip-10-220-46-44 kernel: [22649903.680845] Modules linked in: ipv6 binfmt_misc evbug evdev psmouse i2c_piix4 ixgbevf i2c_core button ext4 crc16 jbd2 mbcache dm_mirror dm_region_hash dm_log dm_mod
Jan 3 22:50:11 ip-10-220-46-44 kernel: [22649903.691804] CPU: 0 PID: 12578 Comm: lsof Not tainted 3.14.48-33.39.amzn1.x86_64 #1
Jan 3 22:50:11 ip-10-220-46-44 kernel: [22649903.696742] Hardware name: Xen HVM domU, BIOS 4.2.amazon 08/24/2006
Jan 3 22:50:12 ip-10-220-46-44 kernel: [22649903.700879] 0000000000000009 ffff880037dc1c90 ffffffff81487535 0000000000000000
Jan 3 22:50:12 ip-10-220-46-44 kernel: [22649903.706058] ffff880037dc1cc8 ffffffff8105d39d ffff8800147b33c0 ffff880037dc1d48
Jan 3 22:50:12 ip-10-220-46-44 kernel: [22649903.711346] ffff8800147b3418 ffff8800147b33c0 ffff8800147b33c0 ffff880037dc1cd8
Jan 3 22:50:12 ip-10-220-46-44 kernel: [22649903.716450] Call Trace:
Jan 3 22:50:12 ip-10-220-46-44 kernel: [22649903.718151] [<ffffffff81487535>] dump_stack+0x45/0x56
Jan 3 22:50:12 ip-10-220-46-44 kernel: [22649903.721634] [<ffffffff8105d39d>] warn_slowpath_common+0x7d/0xa0
Jan 3 22:50:12 ip-10-220-46-44 kernel: [22649903.725658] [<ffffffff8105d47a>] warn_slowpath_null+0x1a/0x20
Jan 3 22:50:12 ip-10-220-46-44 kernel: [22649903.729562] [<ffffffff811bc601>] d_shrink_del+0x71/0x80
Jan 3 22:50:12 ip-10-220-46-44 kernel: [22649903.732957] [<ffffffff811bda24>] shrink_dentry_list+0x64/0xe0
Jan 3 22:50:12 ip-10-220-46-44 kernel: [22649903.736748] [<ffffffff811be868>] shrink_dcache_parent+0x28/0x70
Jan 3 22:50:12 ip-10-220-46-44 kernel: [22649903.740689] [<ffffffff8120fdf6>] proc_flush_task+0xa6/0x190
Jan 3 22:50:12 ip-10-220-46-44 kernel: [22649903.744318] [<ffffffff8105e190>] release_task+0x30/0x450
Jan 3 22:50:12 ip-10-220-46-44 kernel: [22649903.748305] [<ffffffff810946e1>] ? thread_group_cputime_adjusted+0x41/0x50
Jan 3 22:50:12 ip-10-220-46-44 kernel: [22649903.752971] [<ffffffff8105ee7b>] wait_consider_task+0x8cb/0xb00
Jan 3 22:50:12 ip-10-220-46-44 kernel: [22649903.757236] [<ffffffff8105f1b0>] do_wait+0x100/0x240
Jan 3 22:50:12 ip-10-220-46-44 kernel: [22649903.760681] [<ffffffff810602e4>] SyS_wait4+0x64/0xe0
Jan 3 22:50:12 ip-10-220-46-44 kernel: [22649903.764026] [<ffffffff8105def0>] ? task_stopped_code+0x60/0x60
Jan 3 22:50:12 ip-10-220-46-44 kernel: [22649903.768138] [<ffffffff81496fc9>] system_call_fastpath+0x16/0x1b
Jan 3 22:50:12 ip-10-220-46-44 kernel: [22649903.772147] ---[ end trace e3b4a7d896ae3cba ]---
Jan 3 22:51:11 ip-10-220-46-44 kernel: [22649962.676054] INFO: rcu_sched self-detected stall on CPU
Jan 3 22:51:11 ip-10-220-46-44 kernel: [22649962.676054] 0: (14747 ticks this GP) idle=f7d/140000000000001/0 softirq=400397332/400397344
Jan 3 22:51:11 ip-10-220-46-44 kernel: [22649962.676054] (t=14750 jiffies g=44792585 c=44792584 q=188767)
Через несколько часов OOM-killer входит:
Jan 4 00:30:55 ip-10-220-46-44 kernel: [22655946.486183] Out of memory: Kill process 2776 (java) score 654 or sacrifice child
Как видите, OOM-killer выбирает процесс Java и убивает его. В этот момент он потребляет приблизительно. 1,5 Гб оперативной памяти. Это ниже 2 Гб кучи, выделенной с помощью флага -Xmx. Вскоре после этого наше веб-приложение перезагружается несколько раз, пока загрузка процессора не достигнет 100%. Версия ядра ОС 3.14.48-33.39.amzn1.x86_64.
Мой вопрос:
Основываясь на приведенной выше информации, как вы думаете, эта проблема вызвана ОС? Я вижу строку журнала CPU: 0 PID: 12578 Comm: lsof Not tainted 3.14.48-33.39.amzn1.x86_64 #1 и думаю, что это может быть проблема с утилитой lsof из нашего текущего дистрибутива.
Любая помощь будет высоко оценена.