Профилированное приложение с YourKit, все еще не может определить загрузку процессора - PullRequest
4 голосов
/ 29 июля 2011

У меня есть Java-приложение, которое потребляет 100% ресурсов ЦП большую часть времени (на что указывает cacti и top monitor). Мы запустили YourKit (который подтверждает проблему с ресурсом процессора), и он идентифицирует java.net.SocketInputStream.read (byte [], int, int) как самую большую горячую точку в 15% времени. Я считаю, что они не точно измеряют процессорное время для методов, которые выполняют блокировку ввода-вывода, как это делает SocketInputStream.read.

Существует еще 6 идентифицированных горячих точек, но на них приходится менее 20% от общего процессорного времени. все в диапазоне 5% -1%.

Итак, я знаю, что у меня проблема, я вижу проблему, YourKit тоже, но я не приблизился к выявлению настоящей проблемы.

Я довольно новичок в использовании профилировщика и, скорее всего, что-то упустил. Есть идеи?

РЕДАКТИРОВАТЬ: Шон делает хорошее замечание об использовании инструментов, встроенных в систему. Если я использую top и shift + h для просмотра потоков, он отображает где-то от 7 до 15 потоков, и загрузка ЦП резко возрастает. Я не верю, что какой-то один поток вызывает проблему, скорее это кусок кода, который каждый поток выполняет в какое-то время.

Ответы [ 5 ]

3 голосов
/ 29 июля 2011

Я бы порекомендовал запустить это на коробке Solaris, если вы можете. Если у вас нет окна Solaris, рассмотрите возможность установки виртуальной машины с запущенной на ней Open Solaris.

Solaris предлагает инструмент под названием prstat

Prstat работает очень похоже на top, с которым большинство людей знакомо. Важным отличием является то, что prstat может разбить процессы для вас и показать каждый поток внутри процесса.

В вашем случае использование будет прстат -L 0 1

В сочетании с дампом потока (желательно делать это в сценарии), вы можете сопоставить LWPID вместе, чтобы точно определить, какой поток является нагрузкой на процессор.

Вот функциональный пример (я создал маленькое приложение в большом цикле для Poc)

Стандартный топ покажет вам что-то вроде следующего

 PID USERNAME NLWP PRI NICE  SIZE   RES STATE    TIME    CPU COMMAND
  924 username   10  59    0   31M   11M run      0:53 36.02% java

Затем с помощью prstat Была использована следующая команда

 prstat -L 0 1 | grep java > /export/home/username/Desktop/output.txt

И вывод из прстата

PID USERNAME  SIZE   RSS STATE  PRI NICE      TIME  CPU PROCESS/LWPID    
924 username   31M   10M run     30    0   0:00:09  35% java/10
924 username   31M   10M sleep   59    0   0:00:00 0.8% java/3
924 username   31M   10M sleep   59    0   0:00:00 0.6% java/2
924 username   31M   10M sleep   59    0   0:00:00 0.3% java/1

Это может не сильно отличаться от top, но если вы обратите внимание на правую часть данных, PROCESS / LWPID сообщает вам точный поток внутри процесса Java, который потребляет процессор. поток, работающий с облегченным идентификатором процесса (lwpid) 10, потребляет 35% ЦП. Как я упоминал ранее, если вы соедините это с дампом потока, вы можете найти точный поток. Для моего случая это соответствующая часть дампа потока

"Thread-0" prio=3 tid=0x08173800 nid=0xa runnable [0xc60fc000..0xc60fcae0]
   java.lang.Thread.State: RUNNABLE
    at java.util.Random.next(Random.java:139)
    at java.util.Random.nextInt(Random.java:189)
    at ConsumerThread.run(ConsumerThread.java:13)

В верхней строке нити nid можно сопоставить с LWPID. nid = 0xa (то есть 10 декад при преобразовании из Hex)

Если вы можете поместить команды prstat и dump dump в скрипт и запускать его 4-5 раз при высокой загрузке ЦП, вы начнете видеть шаблоны и сможете таким образом определить причину вашей высокой ЦП.

В свое время я видел этот результат от долгого времени работы gc до неправильной конфигурации соединения LDAP. Веселитесь :) 1033 *

2 голосов
/ 29 июля 2011
1 голос
/ 29 июля 2011

Я бы включил трассировку памяти И профилирование процессора и снова посмотрел на профилировщик процессора. Это покажет различные области для оптимизации.

Когда вы говорите, что он использует 100% ЦП, вы можете посмотреть, находится ли он в пространстве пользователя или системы / ядра. например Топ. Профилировщик не покажет вам процессор, используемый в пространстве ядра.

Сколько у вас тем? Если у вас достаточно незанятых потоков, вы можете переключаться между процессорами более чем на 100%. (Тебе нужно было бы много тысяч)

Как и в случае с аналогичными ответами, вполне вероятно, что у вашего приложения слишком много накладных расходов, например чтение сокетов, переключение между потоками, выполнение сборок мусора, которые не выполняют много реальной работы. Профилировщики не так хороши в подборе накладных расходов.

1 голос
/ 29 июля 2011

Профилировщик jvisualvm является удобной альтернативой для сравнения;это включено в JDK.

0 голосов
/ 29 июля 2011

Одна из возможностей заключается в том, что вашей JVM не хватает памяти, поэтому он постоянно выполняет GC.

...