JVM 在 Ubuntu Maverick(AWS EC2 xlarge 实例)上挂起并等待 100 个 IO

JVM 在 Ubuntu Maverick(AWS EC2 xlarge 实例)上挂起并等待 100 个 IO

在 上提问堆栈溢出,转发:

在 AWS 中有一个超大型实例,运行 9 个 Tomcat,堆大小从 256M 到 4G。使用 Ubuntu 10.04,该机器偶尔会挂起几个小时,运行队列很大(30-40),CPU 上没有任何资源,然后恢复。怀疑是 GC,但在使用和不使用 CMS GC 的情况下都出现了重现。

升级到 10.10 后,机器在启动后几个小时内进入 100% 等待状态,并且 CPU 上再次没有任何进程。以下是 top 的输出:

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    
...

GC 日志中没有任何有用的信息(在较大的实例上,使用 MarkSweep,主要 GC 每 5 分钟发生一次,耗时约 4 秒,增量 GC 在 0.1 - 0.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 上均如此。从 10.04 上的 kernel.log 来看:

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

来自 10.10 上的 kernel.log:

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 等)

答案1

EC2 是立即,您遇到的行为与我遇到的行为几乎相同,因此可能是中断影响了您,而不是您的实际设置。如果可以的话,请尝试移至其他区域。

答案2

查看答案这里.总之,降级到 Ubuntu 8.04 LTS 就解决问题了。

答案3

原来与 Ubuntu 10.* 内核和 EC2 large/xlarge 实例中使用的某些 CPU 型号不兼容有关:https://bugs.launchpad.net/ubuntu/+source/linux-ec2/+bug/708920

我们的 AWS 联系人还指出了以下可能相关的问题:https://forums.aws.amazon.com/thread.jspa?threadID=59753

降级到 Ubuntu 8.04 LTS 暂时解决了该问题。

相关内容