Профилирование Java с помощью MonkeyWrench

Рисунок 1 — Графический интерфейс MonkeyWrench

Присоединение MonkeyWrench к уже запущенному целевому приложению:

Существует несколько способов подключения к работающей цели. Прежде чем продолжить, вы должны сначала правильно установить атрибут Boot-Class-Path в файле манифеста jar-файла MonkeyWrench. Причина этого шага заключается в том, что при подключении к работающей JVM JVM необходимо знать, где найти файлы JDK tools.jar и Javassist javassist.jar. Вы можете открыть файл jar MonkeyWrench и отредактировать эту запись напрямую, затем заменить файл манифеста, или вы можете использовать включенный скрипт с именем (несколько грандиозно) installer.bat. Отредактируйте файл и укажите пути к вашему развертыванию JDK и Javassist, и он обновит файл jar MonkeyWrench для вас.

Два способа присоединения к работающей цели: 1) запустить метод main () MonkeyWrench, который будет подключаться к работающей JVM, или 2) использовать графический интерфейс запуска MonkeyWrench, что немного упрощает работу.

См. Включенный скрипт run.bat для подхода командной строки к запуску агента. Вам понадобится идентификатор JVM вашей цели. К счастью, это просто идентификатор процесса ОС. Не забывайте, что вы можете использовать jps для вывода списка всех процессов Java. В сценарии обратите внимание на следующее:

• Путь к классу должен включать файл jar MonkeyWrench, tools.jar и javassist.jar.
• Первый аргумент метода main () — это путь к файлу jar MonkeyWrench. Путь к классу находит файл jar для запуска агента, а первый аргумент командной строки указывает путь агента к API присоединения Sun. Этот путь должен быть полным.
• Второй аргумент командной строки для метода main () MonkeyWrench и единственный аргумент командной строки, передаваемый в пример сценария, — это идентификатор процесса целевого приложения.

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

Второй способ присоединения к работающей цели — это приложение запуска MonkeyWrench (см. Рисунок 2). В каталоге верхнего уровня дистрибутива есть пример сценария Windows, который называется runLauncher.bat. При необходимости измените его так, чтобы он указывал на tools.jar и файл jar MonkeyWrench в вашей системе (примечание: программе запуска не нужно знать о Javassist, но MonkeyWrench все еще знает; MonkeyWrench найдет Javassist, просмотрев запись Boot-Class-Path в своем манифесте). Как только вы запустите запуск, он будет поддерживать актуальный список всех запущенных Java-приложений в системе; дважды щелкните запись для JVM, и графический интерфейс MonkeyWrench запустится.

Рисунок 2 — Пусковая установка MonkeyWrench

MonkeyWrench GUI Обзор

Экран конфигурации MonkeyWrench (см. Рисунок 1) отображает элементы управления для других экранов MonkeyWrench. Раздел «CPU & Memory Profiling» управляет работой вкладок «CPU» и «Memory»; раздел «Профилирование потоков» управляет работой вкладки «Потоки», а раздел «Профилирование сбора мусора» — вкладкой «Сборка мусора». Обратите внимание, что только профилирование процессора и памяти включает внедрение байт-кода, наиболее дорогие операции в профилировщике; Профилирование потоков и сборки мусора использует только bean-компоненты JMX и, таким образом, оказывает гораздо меньшее влияние на производительность целевого приложения. Правая сторона этого экрана — справочный документ, который содержит сокращенную версию информации в этой статье.

Профилирование процессора и памяти включается или выключается одновременно, поэтому эти две вкладки связаны одной конфигурацией. Рассматривая это как одну функцию, эта функция, профилирование потоков и профилирование сборки мусора являются независимыми функциями, которые можно включать или отключать по отдельности. Например, если приложение подвергается тяжелой сборке мусора, MonkeyWrench можно использовать для профилирования только сборки мусора без дополнительных затрат на профилирование метода.

Чтобы не оставлять целевое приложение с внедренным дорогим профилирующим кодом, кнопка «закрыть» в MonkeyWrench отключена, когда профилирование процессора и памяти активно. Чтобы снова включить эту кнопку, необходимо остановить профилирование процессора и памяти на вкладке «Конфигурация».

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

конфигурация

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

Профилирование процессора и памяти

Профилирование ЦП и памяти определяется как внедрение байт-кода для уведомления MonkeyWrench, когда методы или конструкторы вводятся и выходят. Когда происходит одно из этих событий, собранная информация включает системное время и время процессора текущего потока, а также трассировку его стека.

Конструкторы и методы, выбранные для профилирования, определяются регулярным выражением Java. Прежде чем создавать это регулярное выражение, вы должны сначала решить, хотите ли вы, чтобы выражение определяло имена классов или методов. Если вы сопоставляете имена классов, все видимые конструкторы и методы будут инструментированы для каждого соответствующего класса. Если вы сопоставляете имена методов или конструкторов, ваше регулярное выражение должно точно соответствовать этому методу или конструктору. Выражение соответствия включает полное имя пакета класса. Если вы не хотите вводить полный пакет класса, вы можете запустить регулярное выражение с «. *» В качестве ярлыка, хотя в конечном итоге вы можете сопоставить больше, чем вы предполагали. Вы также можете указать регулярное выражение исключения; если он указан, он имеет приоритет над включениями.

Например, если вы хотите применить все методы, начинающиеся с «get» в классе com.example.Printer, ваше регулярное выражение может быть com.example.Printer.get. *, И вы выберете «Инструмент для имени метода / конструктора». , Если вы хотите использовать каждый метод в одном и том же классе, выберите «Инструмент для имени класса» и задайте регулярное выражение com.example.Printer. Обратите внимание, что точка «.» символ фактически означает «соответствовать любому символу», поэтому вышеприведенные выражения должны на самом деле экранировать точку, чтобы соответствовать конкретно этому символу (например, com \ .example \ .Printer), но на практике ленивое регулярное выражение обычно будет соответствовать именно тому, что вы хотите. Просто знайте, что это может соответствовать больше, чем вы ожидаете.

Окно регулярных выражений выполняет проверку вашего выражения в режиме реального времени, когда вы набираете его, чтобы предупредить вас о неправильно сформулированных регулярных выражениях. В этих случаях текст окрашивается в красный цвет, а подсказка подсказывает, в чем проблема. Обратите внимание, что проверка является агрессивной и помечает выражение, которое в конечном итоге может быть правильным, когда вы закончите вводить его (например, когда вы вводите escape-символ или еще не завершили ввод правильной последовательности символов). На рисунке 3 показан пример того, что вы бы увидели, если бы намеревались избежать открытых скобок, где вашим регулярным выражением будет «. * \ («. Проверка происходит при каждом нажатии клавиши, поэтому вводите «(« после «\ ”Вернет дисплей в« действительное »состояние.

Вы можете указать несколько регулярных выражений в каждом окне, разделяя их запятой. Обратите внимание, что все между запятыми считается частью регулярного выражения! Если вы следите за запятой с пробелом, а затем за некоторыми непробельными символами, вы указываете дополнительное регулярное выражение, начинающееся с пробела.

Рисунок 3 — Обратная связь регулярного выражения

Интервал обновления по умолчанию составляет 5 секунд. Это означает, что каждые 5 секунд MonkeyWrench будет обрабатывать структуры данных вызовов методов входа и выхода, вычислять время настенного времени и времени ЦП и обновлять вкладки ЦП и памяти MonkeyWrench. Хотя сбор данных профилирования достаточно дорогой, обновление дисплея также довольно дорого. Обратите внимание, что в потоке событий AWT должна происходить большая активность, чтобы избежать проблем параллелизма со структурами данных графического интерфейса, поэтому при обновлении экранов будет заметно влияние на производительность MonkeyWrench и целевого приложения. Если, кроме того, вы профилируете приложение Swing, пауза обновления становится еще более заметной. По этой причине, если вы не профилируете довольно узкую часть классов в своем приложении,рекомендуется начинать с интервала обновления дисплея 30 секунд.

Флажок «Очистить данные ЦП и памяти при запуске / останове» предназначен для того, чтобы помочь вам сузить данные профилирования для определенных окон времени и отделить результаты профилирования для одного набора классов (согласно заданным вами регулярным выражениям) от результатов для другой набор классов. Одним из преимуществ MonkeyWrench является способность очищать данные по требованию (например, вы можете очистить данные профилирования непосредственно перед началом дорогостоящей операции в целевом приложении). Этот флажок является еще одним способом выделения результатов профилирования.

Поскольку внедрение байт-кода само по себе является дорогостоящей операцией, индикатор выполнения запускается как при инструментировании классов, так и при восстановлении их исходного состояния. Во время профилирования вы можете нажать «Просмотреть инструментальные классы» (или «Просмотреть инструментальные методы», в зависимости от того, какой выбор инструментов вы сделали), чтобы убедиться, что вы инструктировали классы или методы, которые вы указали в своих регулярных выражениях.

Как упоминалось ранее, после включения профилирования кнопка «Закрыть» на MonkeyWrench отключена. Этот шаг делается для предотвращения утилизации профилировщика, пока целевое приложение все еще оснащено инструментами. Чтобы снова включить кнопку «Закрыть» MonkeyWrench, остановите профилирование процессора и памяти.

Более подробное обсуждение фактических данных профилирования, собранных и отображенных во время этого типа профилирования, см. В разделе «Профилирование процессора и памяти».

Профилирование потоков

Настройка профилирования потоков относительно проста; все, что вам нужно, это решить, как часто обновляется дисплей (этот интервал не зависит от интервала профилирования процессора и памяти) и хотите ли вы, чтобы данные профилирования потока очищались при запуске и остановке. MonkeyWrench поддерживает записи всех потоков, которые он видел во время профилирования; очистка данных профилирования (с помощью кнопки «… Сейчас» или при запуске и остановке профилирования) очищает память потоков, которые больше не работают. Обратите внимание, однако, что есть некоторые данные, которые не очищаются; например, совокупное время ЦП потока извлекается из bean-компонента Thread JMX и будет включать в себя время ЦП, накопленное до того, как в последний раз был очищен дисплей MonkeyWrench. Хороший рекомендуемый интервал обновления здесь составляет одну секунду.

Более подробное обсуждение данных, собранных и отображенных для профилирования потоков, см. В разделе «Профилирование потоков».

Профилирование сборки мусора

Параметры конфигурации для профилирования сборки мусора аналогичны параметрам для профилирования потоков. Рекомендуемый (и используемый по умолчанию) интервал обновления дисплея составляет пять секунд, хотя его можно установить равным одной секунде. Вы также можете указать, следует ли очищать данные при запуске и остановке профилирования.

Обсуждение данных, отображаемых в профилировании сборки мусора, и мотивации для отображений MonkeyWrench можно найти в «Профилировании сбора мусора».

Профилирование процессора и памяти

Как только вы запустили профилирование ЦП и памяти, информация накапливается на вкладках «ЦП» и «Память» на каждом интервале обновления дисплея. Вкладка «ЦП» предназначена для отслеживания времени, затрачиваемого на методы и конструкторы, а вкладка «Память» предназначена для отслеживания размещения объектов, заданных вашими регулярными выражениями. Обратите внимание, что если вы работаете только с именами методов, вы не получите никакого вывода на вкладке «Память», так как никакие конструкторы не будут оснащены.

На рисунке 4 показана вкладка ЦП при профилировании веб-службы качества воды на основе NWIS. Несколько вариантов были выбраны, чтобы выделить большинство функций этой вкладки. По мере того, как сигнатуры вызовов методов и конструкторов накапливаются на дисплее, таблица в верхней половине экрана отображает время ЦП и время настенного времени для каждого метода, а также процентное отношение общего времени ЦП и времени настенного времени, а также количество вызовов. Обратите внимание, что итоговые значения основаны на общем времени, накопленном для всех используемых инструментов (не для всех методов в целевом приложении). В этом примере в таблице только несколько методов, но количество записей может исчисляться сотнями или тысячами. По этой причине предоставляется окно поиска с кнопками «найти далее» и «найти предыдущий».

Метод getSiteName () StreamMonitor выбран в таблице конструктора / метода. Когда вы выбираете запись в этой таблице, сводная таблица сайтов в нижнем левом углу заполняется списком уникальных подписей трассировки стека, связанных с этим вызовом метода (термин «сайт» взят из утилиты профилирования hprof) , В этом случае идентифицируется только один сайт; щелчок по этой записи заполняет нижнюю правую текстовую область самой трассировкой стека.

Рисунок 4 — Экран процессора

Обе таблицы на этом экране могут быть отсортированы по всем столбцам, по возрастанию или по убыванию. Как правило, верхняя таблица сортируется по «% общего времени ЦП» по убыванию, а таблица сводных данных по сайту — по убыванию по столбцу «Вхождения». Два столбца процента в верхней таблице отображают пропорциональную зеленую полосу для отображения процента, а также для отображения суммы.

Note there are two “View Threads” buttons. When you select “View Threads” on the upper table, containing the method signature data, you will open a small dialog listing the threads used to invoke that method, with a count of the number of times each thread called that method or constructor. When you select the “View Threads” button above the stack‐trace text area, you display only the threads used to call the method or constructor through the selected site or stack trace. In this example, the thread “pool‐1‐thread‐1” (a naming convention used by the Java SE webservice implementation) is the thread that has called this method for all of the occurrences (10, in this case) since we started profiling or cleared the data.

In a more‐complex or more heavily‐used application, there may in fact be many sites, or stack‐trace signatures, for a particular constructor or method call, and there may be several threads involved. These may be just different threads from a pool, but in some cases the thread display can reveal potential issues. For example, it may show that on a number of occasions, a highly compute‐intensive method is being called on the AWT event thread. Having the stack trace associated with this thread would then simplify the job of determining how such a call got scheduled on the thread responsible for GUI updates.

Finally, note the two “Clear…” buttons on this screen. Every screen (except the Configuration screen) in the MonkeyWrench contains these two buttons; one to clear the profiling data in the current screen, and one to clear the profiling data in all screens. This feature is provided as a convenience to allow you to clear the profiling data just before an important event occurs in your target application.

Figure 5 shows the “Memory” screen of the MonkeyWrench profiler, this time for the popular “jEdit” Java file editor, after a couple of files have been opened, parsed and displayed. As you might expect, a lot of objects get constructed by an editor during this type of activity, so the memory usage table (similar to the method/constructor table in the CPU screen, but in this case, showing objects instantiated) has quite a few entries. This application is an example of a case where the search window (identical in operation to the one in the CPU screen) can be quite useful.

Figure 5 — The Memory Screen

In this case, we have selected jEdit’s ServiceManager’s inner class Descriptor. We see that there are 34 instances of this class for a total of 1088 bytes (note that the object size, as returned by the instrumentation hooks of the JVM, is a shallow size). We selected the “View Threads” button above the upper table, which displays the threads for all 34 occurrences of this object instantiation (unlike the lower “View Threads” button, which would just show the 4 occurrences for the selected site summary) and can see that 32 times, the Descriptor was instantiated on the AWT event thread, but 2 times it was instantiated on one of jEdit’s I/O threads.

Working our way down the list in the site summary table, we could find the one (or at most two) sites where the jEdit I/O thread was used to instantiate one of these objects. In fact, if we scroll down through the list of sites (practical in this case only because there are not that many sites) we would see that it is stack trace #15 which was used by this particular thread, as seen in Figure 6. Matching a thread with a stack trace can help you find errors in applications, especially those that spawn a chain of thread‐start operations (in some cases, handing over to the AWT event thread) in the process of handling a request.

Figure 6 — Memory Screen Detail View

As with the CPU screen, the Memory screen has fully sortable tables and buttons to clear the CPU and Memory profiling data, or to clear all profiling data. While the sizes reported by the JVM for each object are probably not that useful, it can be revealing to see just how many instances of a class are being created by an application, particularly if the relevant constructor involves some resource‐intensive activity. In this case, you should also be seeing large CPU‐time numbers for the constructor on the MonkeyWrench’s CPU screen.

Thread Profiling

The MonkeyWrench Thread profiling screen displays, for each active thread, the following data:

• Thread ID
• Thread Name
• Thread state
• % of total CPU time (of all active threads)
• Total CPU time consumed by the thread
• CPU time consumed by the thread in the display interval
• Total times thread has blocked
• Number of times thread has blocked during the display interval
• Total time thread has spent blocked
• Time thread has spent blocked during the display interval

As with the other screens in the MonkeyWrench, all columns in the table are sortable, descending or ascending. In practice, you will usually sort on either the “% of Total CPU Time” or the “CPU Time In Window” columns, descending, showing you the most active threads either in general or for the current sampling interval (which you set in the Configuration screen when you started Thread profiling).

The bottom half of this screen displays a table of blocked and deadlocked threads. Because the MonkeyWrench has a significant impact on the application being profiled, many times a thread will block on a lock held by a MonkeyWrench thread (for example, the ThreadStatisticsUpdater), and vice‐versa. These blocks would not occur if the MonkeyWrench were not profiling your application, of course. For this reason, a checkbox (labeled “Ignore Profiler‐Caused Blocks”) is available; check this box and the MonkeyWrench will not display any blocks where a MonkeyWrench‐specific thread is either blocking or being blocked. In the example, we have left the box unchecked because there are no jEdit‐caused blocks, and we want to show examples of the data displayed in this table.

Figure 7 — Threads Screen

The Blocked and Deadlocked Threads table displays the following data for each block:

• Timestamp
• ID of blocked thread
• Name of blocked thread
• Boolean, true if the thread is deadlocked
• The lock name
• ID of the thread holding the lock
• Name of the thread holding the lock

In cases where a particular block occurs frequently, it is helpful to know the path taken by one of the threads. Selecting a entry in this table produces a window with the stack trace for that particular occurrence. Figure 8 is an example of one of the block events found when the threads were inspected.

Figure 8 — Blocked Thread Stack Trace View

Note from Figure 7 that all of the MonkeyWrench‐caused blocks have the same lock – an instance of a com.gorillalogic.profiler.GorillaProfiler. This is the MonkeyWrench main profiler class. Since this is the class that every instrumented method in the target application calls to notify of method entries and exits, it’s a frequent object of contention. Of course this is only true during profiling, which is why the Threads screen provides the checkbox to suppress display of these contention events.

As with the other MonkeyWrench screens, the Threads screen provides buttons to clear Thread profiling data, as well as all profiling data. Additionally, it provides a button to clear the history of blocked and deadlocked threads.

Garbage Collection Profiling

While most Java profilers provide a view on garbage‐collection activity, the MonkeyWrench provides a slightly different perspective than most. This view, found on the Garbage Collection screen and shown in Figure 9, provides two time series: one of the number of garbage collections for each display interval, and one of the CPU time spent in garbage collection during the interval.

Most profilers provide a plot of the amount of memory used in a generation as a function of time. While this view can be useful when garbage collection does not occur frequently, it breaks down in situations where (for example), the Eden generation is being collected multiple times per second (which is not an unusual situation). In these cases, the sampling interval of the profiler is too large to capture the fact that many collections are occurring during each sampling interval, and a plot of the generation memory as a function of time can appear to be a random number. Not being aware of this situation can cost a lot of troubleshooting time.

When MonkeyWrench first begins monitoring garbage collection, the cursor for the current time (represented with a t = Now cursor in red) progresses from the left to the right edge of the screen. Time is marked in time before the present time (that is, the cursor), displaying the sampling interval chosen on the Configuration screen. When the “t = Now” cursor reaches the right edge of the graph, the x axis remains fixed and the data points scroll to the left. A combo box at the top of the screen allows you to switch between garbage collectors.

Undergoing multiple garbage collections per second is not necessarily undesirable; more important is the amount of time spent in garbage collection during an interval. In the example shown in Figure 9, at peak, about 40 minor collections are occurring per second, burning about 50 msec of CPU time. If an application is experiencing a very large number of collections (minor or otherwise) in an interval, and using a lot of CPU time to collect, it might signal that the generation is sized too small, or it may indicate that there is an issue in the target application requiring attention.

Figure 9 — Garbage Collection Screen

For example, when profiling a Swing application, if you notice that a lot of minor collections occur during certain mouse movements, or when selecting a menu item, it may point to an over‐engineered AWT event listener. While the collection display won’t actually point to the section of code at fault, knowing something about what is happening when the collection activity spikes will generally help narrow down the list of possible causes.

As with the other MonkeyWrench screens, two “clear” buttons are provided: one to clear garbage‐collection profiling data, and another to clear all profiling data. This feature allows you to clear the display before triggering a target application event of interest, so that the display will show only activity since the event of interest occurred.

Concluding Remarks and Notes

MonkeyWrench uses the Javassist bytecode injection library to insert calls to the profiler. While this package is extremely simple to use, a number of issues associated with it limit the functionality of the MonkeyWrench. When Javassist is used to instrument core or extension Java classes, the resulting application is disabled, as the classloader becomes unable to locate the MonkeyWrench profiler classes. Future work in MonkeyWrench will involve swapping in other libraries (such as BCEL, or ASM) in search of improvements in this area. While it’s not currently clear exactly what causes this problem (and Javassist may not actually be the cause of the issue), the current approach in MonkeyWrench is to avoid instrumenting any core (java.*), extension (javax.*) or Sun (com.sun.*) classes. It is a development goal to eventually instrument these classes, however. To avoid circular dependencies, neither the MonkeyWrench nor the Javassist classes are instrumented, either (a situation which is not likely to change, as no great value would be obtained from doing so).

Because of the way that MonkeyWrench instruments classes, it cannot provide what is typically called “self time” (time spent only in the method and not in any methods called by the method).

Since the MonkeyWrench is a substantial Swing application in its own right and runs in the same JVM as your target application, you may need to increase the heap space for your application when profiling it. On rare occasions, the additional overhead of MonkeyWrench may cause stack size overflows, a situation which can be remedied with the JVM option –Xss. Note that StackOverflowErrors usually point to an error in application logic (for example, an infinite recursion), in which case increasing the stack size usually doesn’t help. If the error only occurs when you are profiling, though, then a simple increase above the default should get past the issue. You probably won’t see this problem, but if you do, it will probably happen when you are profiling a parser or interpreter.

A final recommendation on using the MonkeyWrench is to narrow down, as quickly as is practical, the set of classes that you wish to profile. Profiling all of an application’s classes (with the regular expression “.*”) can in some cases slow the target application down too much to profile it. If you must instrument all classes, set the display update interval to the maximum (30 seconds) and use the CPU screen to narrow the search down to a few packages. Alternatively, if you find that a package of little or no interest is incurring a great deal of profiling overhead (for example, the parse method of an XML parser), another approach is to list the package in the “Excluded Classes” regular expression.

This was a long, and hopefully comprehensive, tour. If you use MonkeyWrench, perhaps you’ll encounter some of the particular profiling scenarios which prompted its development. In any case, I hope you find it useful and that it finds a spot in your profiling toolbox!