Назад | Перейти на главную страницу

JVM зависает с ожиданием 100 операций ввода-вывода на Ubuntu Maverick (экземпляр AWS EC2 xlarge)

Задал этот вопрос на переполнение стека, репост:

У вас есть экземпляр xlarge в AWS, на котором запущено 9 Tomcats с кучей от 256M до 4G. В Ubuntu 10.04 коробка периодически зависает на несколько часов с огромной очередью выполнения (30-40) и ничего не загружает процессор, а затем восстанавливается. Заподозрил GC, но перепроверил как с CMS GC, так и без нее.

После обновления до 10.10 машина переходит в режим 100% ожидания через пару часов после запуска, опять же без процессов на ЦП. Вот вывод сверху:

top - 18:33:44 up  3:11,  2 users,  load average: 26.99, 26.80, 25.82
Tasks: 126 total,   1 running, 125 sleeping,   0 stopped,   0 zombie
Cpu(s):  0.0%us,  0.0%sy,  0.0%ni,  0.0%id,100.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:  15373736k total, 15174780k used,   198956k free,    51288k buffers
Swap:        0k total,        0k used,        0k free,  6208956k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                       
 5910 tomcat6   20   0  746m 361m 9872 S    0  2.4   2:01.32 java                                                                           
10147 tomcat6   20   0  919m 173m 9.8m S    0  1.2   0:22.60 java                                                                           
12328 ubuntu    20   0 19276 1320  968 R    0  0.0   0:01.41 top                                                                            
    1 root      20   0 23864 2012 1300 S    0  0.0   0:00.38 init                                                                           
    2 root      20   0     0    0    0 S    0  0.0   0:00.00 kthreadd    
...

Ничего полезного в журнале сборщика мусора (в более крупных экземплярах с MarkSweep основной сборщик мусора происходит каждые 5 минут и занимает ~ 4 с, инкрементный завершается за .1 - .2 с, много свободной памяти во всех поколениях).

Вот вывод dstat:

----total-cpu-usage---- -dsk/total- -net/total- ---paging-- ---system--
usr sys idl wai hiq siq| read  writ| recv  send|  in   out | int   csw 
  5   1  51  43   0   0|  63k  512k|   0     0 |   0     0 | 435   401 
  0   0   0 100   0   0|   0     0 |  52B  834B|   0     0 | 185   315 
  0   0   0 100   0   0|   0     0 |4997B   14k|   0     0 | 247   360 
  0   0   0 100   0   0|   0     0 |  52B  354B|   0     0 | 146   318 
  0   0   0 100   0   0|   0     0 |  52B  354B|   0     0 | 149   314 
  0   0   0 100   0   0|   0     0 |  52B  354B|   0     0 | 145   318 
  0   0   0 100   0   0|   0     0 |4997B   14k|   0     0 | 227   345 
  0   0   0 100   0   0|   0     0 |  52B  354B|   0     0 | 158   325 
  0   0   0 100   0   0|   0     0 |  52B  354B|   0     0 | 160   306 
  0   0   0 100   0   0|   0     0 |  52B  354B|   0     0 | 148   319 
  0   0   0 100   0   0|   0     0 |4619B   14k|   0     0 | 224   353

В то время, когда ожидание начало зашкаливать, это было в конце загрузки / разбора кучи больших файлов из s3 и их локальной записи на диск (хранилище экземпляров). Дамп потока (на jconsole не может убить -3 на поле - зависает), показывает, что один поток заблокирован при записи на диск.

Я потерян. Какой камень повернуть следующим? Что здесь может происходить?

ОБНОВИТЬ:

Похоже, это связано с Ubuntu Maverick зависает: «задача заблокирована более 120 секунд», 10.04 и 10.10. Из kernel.log от 10.04:

Apr 19 02:47:11 ip-10-110-67-175 kernel: [51985.909553] INFO: task kjournald:91 blocked for more than 120 seconds.
Apr 19 02:47:11 ip-10-110-67-175 kernel: [51985.909565] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Apr 19 02:47:11 ip-10-110-67-175 kernel: [51985.909571] kjournald     D ffff8803be10c424     0    91      2 0x00000000
Apr 19 02:47:11 ip-10-110-67-175 kernel: [51985.909575]  ffff8803be147d50 0000000000000246 0000000000000000 ffff8803be147cd0
Apr 19 02:47:11 ip-10-110-67-175 kernel: [51985.909579]  0000000000000000 ffff8803be147d18 ffff8803be1448b8 ffff8803be147fd8
Apr 19 02:47:11 ip-10-110-67-175 kernel: [51985.909581]  ffff8803be144500 ffff8803be144500 ffff8803be144500 ffff8803be147fd8
Apr 19 02:47:11 ip-10-110-67-175 kernel: [51985.909584] Call Trace:
Apr 19 02:47:11 ip-10-110-67-175 kernel: [51985.909595]  [<ffffffff811ff29d>] journal_commit_transaction+0x18d/0xf20
Apr 19 02:47:11 ip-10-110-67-175 kernel: [51985.909601]  [<ffffffff81059d50>] ? autoremove_wake_function+0x0/0x40
Apr 19 02:47:11 ip-10-110-67-175 kernel: [51985.909606]  [<ffffffff8104c1be>] ? try_to_del_timer_sync+0x6e/0xd0
Apr 19 02:47:11 ip-10-110-67-175 kernel: [51985.909610]  [<ffffffff812040da>] kjournald+0xfa/0x290
Apr 19 02:47:11 ip-10-110-67-175 kernel: [51985.909613]  [<ffffffff81059d50>] ? autoremove_wake_function+0x0/0x40
Apr 19 02:47:11 ip-10-110-67-175 kernel: [51985.909615]  [<ffffffff81203fe0>] ? kjournald+0x0/0x290
Apr 19 02:47:11 ip-10-110-67-175 kernel: [51985.909617]  [<ffffffff8105986e>] kthread+0x8e/0xa0
Apr 19 02:47:11 ip-10-110-67-175 kernel: [51985.909622]  [<ffffffff8100a70a>] child_rip+0xa/0x20
Apr 19 02:47:11 ip-10-110-67-175 kernel: [51985.909625]  [<ffffffff810597e0>] ? kthread+0x0/0xa0
Apr 19 02:47:11 ip-10-110-67-175 kernel: [51985.909627]  [<ffffffff8100a700>] ? child_rip+0x0/0x20

Из kernel.log от 10.10:

Apr 18 05:58:07 ip-10-70-147-162 kernel: [899447.462810] INFO: task kjournald:716 blocked for more than 120 seconds.
Apr 18 05:58:07 ip-10-70-147-162 kernel: [899447.462834] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Apr 18 05:58:07 ip-10-70-147-162 kernel: [899447.462842] kjournald     D ffff880005bfb980     0   716      2 0x00000000
Apr 18 05:58:07 ip-10-70-147-162 kernel: [899447.462849]  ffff8803aee4ba20 0000000000000246 ffff880300000000 0000000000015980
Apr 18 05:58:07 ip-10-70-147-162 kernel: [899447.462855]  ffff8803aee4bfd8 0000000000015980 ffff8803aee4bfd8 ffff8803aef1c4a0
Apr 18 05:58:07 ip-10-70-147-162 kernel: [899447.462861]  0000000000015980 0000000000015980 ffff8803aee4bfd8 0000000000015980
Apr 18 05:58:07 ip-10-70-147-162 kernel: [899447.462867] Call Trace:
Apr 18 05:58:07 ip-10-70-147-162 kernel: [899447.462880]  [<ffffffff815a20f3>] io_schedule+0x73/0xc0
Apr 18 05:58:07 ip-10-70-147-162 kernel: [899447.462887]  [<ffffffff812a2f1c>] get_request_wait+0xcc/0x1a0
Apr 18 05:58:07 ip-10-70-147-162 kernel: [899447.462893]  [<ffffffff8107f080>] ? autoremove_wake_function+0x0/0x40
Apr 18 05:58:07 ip-10-70-147-162 kernel: [899447.462897]  [<ffffffff812a3083>] __make_request+0x93/0x4b0
Apr 18 05:58:07 ip-10-70-147-162 kernel: [899447.462903]  [<ffffffff81102cc5>] ? mempool_alloc_slab+0x15/0x20
Apr 18 05:58:07 ip-10-70-147-162 kernel: [899447.462907]  [<ffffffff812a1c63>] generic_make_request+0x1b3/0x540
Apr 18 05:58:07 ip-10-70-147-162 kernel: [899447.462911]  [<ffffffff81102cc5>] ? mempool_alloc_slab+0x15/0x20

Кажется, что это всегда начинается с kjournald, а затем появляется другой процесс с аналогичным сообщением (flush, java и т. Д.)

Посмотреть ответ Вот. Короче говоря, переход на Ubuntu 8.04 LTS решил проблему.

EC2 - это вниз прямо сейчас, и поведение, которое вы испытываете, почти идентично тому, которое испытываю я, поэтому, вероятно, на вас влияет сбой, а не ваша фактическая настройка. Попробуйте перейти в другую зону, если это для вас вариант.

Оказалось, что это связано с несовместимостью между ядрами Ubuntu 10. * и некоторыми моделями ЦП, используемыми в экземплярах EC2 large / xlarge: https://bugs.launchpad.net/ubuntu/+source/linux-ec2/+bug/708920

Наш представитель AWS также указал на следующую проблему, которая может быть связана: https://forums.aws.amazon.com/thread.jspa?threadID=59753

Переход на Ubuntu 8.04 LTS пока решил проблему.