Главная

Какой Java поток нагружает мой процессор

2012-10-02 в 9:07, admin, рубрики: java, threads, переводы, метки: java, threads

Что Вы делаете, когда Ваше Java приложение потребляет 100% ЦП? Оказывается Вы легко можете найти проблемные потоки, используя встроенные Unix и JDK утилиты. Никакие инструменты профилирования не потребуются.
С целью тестирования мы будем использовать простую программу:

public class Main {
    public static void main(String[] args) {
        new Thread(new Idle(), "Idle").start();
        new Thread(new Busy(), "Busy").start();
    }
}
 
class Idle implements Runnable {
 
    @Override
    public void run() {
        try {
            TimeUnit.HOURS.sleep(1);
        } catch (InterruptedException e) {
        }
    }
}
 
class Busy implements Runnable {
    @Override
    public void run() {
        while(true) {
            "Foo".matches("F.*");
        }
    }
}

Как вы видите, в данном куске кода запускается 2 потока. Idle не потребляет ресурсы ЦП(
запомните, спящие потоки потребляют память, но не процессор), в то время как Busy сильно нагружает ЦП, выполняя парсинг регулярных выражений, и другие сложные процессы.
Как мы можем быстро найти проблемный кусок кода нашей программы? Во-первых мы будем использовать 'top', чтобы найти Id процесса(PID) java приложения. Это весьма просто:

top -n1 | grep -m1 java

Мы увидим первую строку вывода 'top', содержащую слово «java»:

22614 tomek     20   0 1360m 734m  31m S    6 24.3   7:36.59 java

Первая колонка это PID. К сожалению, оказалось, что 'top' использует ANSI escape codes for colors. К счастью, я нашел perl скрипт, чтобы удалить лишние символы и наконец-то извлечь PID.

top -n1 | grep -m1 java | perl -pe 's/e[?.*?[@-~] ?//g' | cut -f1 -d' '

Возвращает:

Теперь, когда мы знаем PID процесса, мы можем использовать top -H, для поиска проблемных Linux потоков. Ключ -H отображает список всех потоков, и теперь колонка PID это ID потока:

top -n1 -H | grep -m1 java
top -n1 -H | grep -m1 java | perl -pe 's/e[?.*?[@-~] ?//g' | cut -f1 -d' '

Возвращает:

25938 tomek     20   0 1360m 748m  31m S    2 24.8   0:15.15 java
25938

Итого мы имеем ID процесса JVM и ID потока Linux. А теперь самое интересное: если вы посмотрите на вывод jstack (доступен в JDK), каждый поток имеет NID, который написан после имени.

Busy' prio=10 tid=0x7f3bf800 nid=0x6552 runnable [0x7f25c000]
    java.lang.Thread.State: RUNNABLE
        at java.util.regex.Pattern$Node.study(Pattern.java:3010)

Параметр nid=0x6552 это Hex представление ID потока:

printf '%x' 25938
6552

Теперь объединим всё в один скрипт:

#!/bin/bash
PID=$(top -n1 | grep -m1 java | perl -pe 's/e[?.*?[@-~] ?//g' | cut -f1 -d' ')
NID=$(printf '%x' $(top -n1 -H | grep -m1 java | perl -pe 's/e[?.*?[@-~] ?//g' | cut -f1 -d' '))
jstack $PID | grep -A500 $NID | grep -m1 '^$' -B 500

Последняя строка запускает jstack с определённым PID и выводит поток с совпадающим NID. Тот самый поток и будет являться проблемным.
Выполняем:

./profile.sh
"Busy" prio=10 tid=0x7f3bf800 nid=0x6552 runnable [0x7f25c000]
    java.lang.Thread.State: RUNNABLE
        at java.util.regex.Pattern$Node.study(Pattern.java:3010)
        at java.util.regex.Pattern$Curly.study(Pattern.java:3854)
        at java.util.regex.Pattern$CharProperty.study(Pattern.java:3355)
        at java.util.regex.Pattern$Start.<init>(Pattern.java:3044)
        at java.util.regex.Pattern.compile(Pattern.java:1480)
        at java.util.regex.Pattern.<init>(Pattern.java:1133)
        at java.util.regex.Pattern.compile(Pattern.java:823)
        at java.util.regex.Pattern.matches(Pattern.java:928)
        at java.lang.String.matches(String.java:2090)
        at com.blogspot.nurkiewicz.Busy.run(Main.java:27)
        at java.lang.Thread.run(Thread.java:662)

Источник

Автор: syntax