28 февр. 2013 г.

java: who has eaten my cpu ?

Приходит давеча коллега и показывает запущенное простенькое java приложение, которое выжирает > 100% cpu без какой-либо на то видимой причины.

Святые угодники! что делать ?

$ ps  -o nlwp -p pid
NLWP
212
Количество ниток не запредельное, тоже мне невидаль, 212 ниток в java приложении.
$ kill -3 pid

И читаем thread dump в stdout. И увы тоже ничего криминального не видим - i/o работает, кто-то спит. Но! есть в это приложении один нюанс...

Оно для некоторых своих целей использует... карманный ядерный реакторdisruptor (но! это не gflogger).

А давайте-ка посмотрим, какие именно никти выедают ядра:
$ ps -Lo pid,%cpu,lwp -p pid | grep -v "LWP" | awk '{if ($2 > 0.5){printf "%d 0x%2x\n", $2, $3}}'
35 0x24c
30 0x255
30 0x256
30 0x29D
20 0x2d0
18 0x35e
18 0x4f4
18 0x7e7

Т.е получим информацию о потребении cpu > 0.5 на каждый light weight process нашего приложения (и сразу в шестнадцатиричном виде).

А это есть не что иное как nid нитки в нашем приложении, те самые native id, которые используются в thread dump отчёте (kill -3):

"XXXXExecutor1" prio=10 tid=0x00007f29b58b7000 nid=0x24c runnable [0x00007f29a6baa000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:317)
        at com.lmax.disruptor.MultiThreadedClaimStrategy.waitForCapacity(MultiThreadedClaimStrategy.java:186)
        at com.lmax.disruptor.MultiThreadedClaimStrategy.incrementAndGet(MultiThreadedClaimStrategy.java:116)
        at com.lmax.disruptor.Sequencer.next(Sequencer.java:126)
        at XXXXXXXXXXXXXXXXXXXXXXXXXXXXX
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:662)

"XXXXExecutor2" prio=10 tid=0x00007f29b4bee800 nid=0x255 runnable [0x00007f29a67a6000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:317)
        at com.lmax.disruptor.MultiThreadedClaimStrategy.waitForCapacity(MultiThreadedClaimStrategy.java:186)
        at com.lmax.disruptor.MultiThreadedClaimStrategy.incrementAndGet(MultiThreadedClaimStrategy.java:116)
        at com.lmax.disruptor.Sequencer.next(Sequencer.java:126)
        at XXXXXXXXXXXXXXXXXXXXXXXXXXXXX
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:662)

"XXXXExecutor3" prio=10 tid=0x00007f29b4bf0800 nid=0x256 runnable [0x00007f29a66a5000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:317)
        at com.lmax.disruptor.MultiThreadedClaimStrategy.waitForCapacity(MultiThreadedClaimStrategy.java:186)
        at com.lmax.disruptor.MultiThreadedClaimStrategy.incrementAndGet(MultiThreadedClaimStrategy.java:116)
        at com.lmax.disruptor.Sequencer.next(Sequencer.java:126)
        at XXXXXXXXXXXXXXXXXXXXXXXXXXXXX
        at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:662)


И конечно же виноват не сам disruptor, а какой-то мучудак, который не правильно его заиспользовал.

Комментариев нет: