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

在stackoverflow上提出这个问题,转贴:

AWS中有一个xlarge实例,运行9个Tomcat,堆栈从256M到4G。 使用Ubuntu 10.04,这个盒子会偶尔挂起几个小时,运行大量的队列(30-40),CPU上没有任何东西,然后恢复。 是怀疑GC,但有和没有CMS的GC GC。

升级到10.10之后,机器在启动后的几个小时内进入100%等待,再次在CPU上没有进程。 这是从顶部输出:

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秒,增量在0.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下载/parsing一堆大文件并将它们本地写入到磁盘(实例存储)中。 线程转储(在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开始,然后其他进程显示类似的消息(刷新​​,Java等)

EC2 现在正在运行 ,您所遇到的行为与我所遇到的行为几乎完全相同,因此可能是影响您的中断,而不是您的实际设置。 尝试移动到不同的区域,如果这是您的select。

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

原来与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现在解决了这个问题。