Почему JProfiler не показывает мои классы/методы в профилировании тестов maven?

У меня очень длинные тесты в моей сборке maven. Эти тесты представляют собой интеграционные тесты, выполняемые с отказоустойчивым подключаемым модулем (mvn verify).

Я пытаюсь профилировать эти тесты с помощью JProfiler.

Тесты выполняются правильно, но я не вижу ничего полезного в JProfiler, как будто JProfiler их отфильтровывает.

Я использую openSUSE 13.1 x64 с Maven 3.2.1 и JProfiler 8.0.5.

Настройки сеанса JProfiler являются настройками по умолчанию с двумя изменениями:

  • Автоматически запускать профилирование ЦП при запуске
  • Оставить виртуальную машину в рабочем состоянии после завершения выполнения (чтобы включить отслеживание информации)

Я запускаю профилированную сборку с помощью этой команды:

MAVEN_OPTS="-agentpath:/opt/jprofiler8/bin/linux-x64/libjprofilerti.so=port=8849" mvn verify

Maven и JProfiler работают на одном компьютере (локальное профилирование).

Сборка запускается нормально:

$ MAVEN_OPTS="-agentpath:/opt/jprofiler8/bin/linux-x64/libjprofilerti.so=port=8849" mvn verify
JProfiler> Protocol version 39
JProfiler> Using JVMTI
JProfiler> JVMTI version 1.1 detected.
JProfiler> 64-bit library
JProfiler> Listening on port: 8849.
JProfiler> Instrumenting native methods.
JProfiler> Can retransform classes.
JProfiler> Can retransform any class.
JProfiler> Native library initialized
JProfiler> VM initialized
JProfiler> Waiting for a connection from the JProfiler GUI ...
JProfiler> Using dynamic instrumentation
JProfiler> Time measurement: elapsed time
JProfiler> CPU profiling enabled
[INFO] Scanning for projects...
[INFO] 
[INFO] Using the builder org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder with a thread count of 1
[INFO]                                                                         
[INFO] ------------------------------------------------------------------------
[INFO] Building...
[...]

а также нормально заканчивается:

[...]
Results :

Tests run: 2766, Failures: 0, Errors: 0, Skipped: 0

[WARNING] File encoding has not been set, using platform encoding UTF-8, i.e. build is platform dependent!
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 19:31 min
[INFO] Finished at: 2014-06-18T11:38:49+01:00
[INFO] Final Memory: 21M/107M
[INFO] ------------------------------------------------------------------------
JProfiler> Keeping VM alive until frontend disconnects.

JProfiler Hot Spots CPU показывает мне это:

введите здесь описание изображения

Как по мне, это бесполезный материал, только методы, связанные с maven (архивирование, загрузка классов).

Когда я пытаюсь пройти (открыть трассировку точки доступа), я не нахожу ничего, связанного с тестами, которые я запускаю.

Кроме того, измеренное прошедшее время (если я добавлю собственное время первых 10 горячих точек) в значительной степени незначительно (~10s) по сравнению с фактическим общим временем (~19 mins 30s).

ИЗМЕНИТЬ:

Сначала я запускал профилирование тестов с помощью своей IDE (IntelliJ IDEA) и плагина JProfiler, но остановился из-за странного поведения. Казалось, что тесты шли бесконечно, но ничего не делали. Я предположил, что это исходит из IDE (или плагина), потому что тесты проходят через maven нормально.

РЕДАКТИРОВАТЬ 2:

Благодаря предложению @IngoKegel, если я выберу «Все состояния», у меня будет больше информации:

введите здесь описание изображения

Я вижу еще 4 горячие точки. Однако они по-прежнему не дают мне полезной информации:

  1. является «отфильтрованным/прямым вызовом» к j.u.c.ThreadPoolExecutor$Worker.run
  2. — это одиночный вызов из Maven (plexus) в j.l.r.Method.invoke (+ несущественные вызовы)
  3. и 4. являются "фильтрованными/прямыми вызовами" к o.a.maven.p.surefire.booterclient.o.ThreadStreamConsumer$Pumper.run

Прошедшее время намного лучше, но я все еще не вижу ничего исходящего от «моих» занятий.

Почему мои курсы по-прежнему фильтруются? Есть ли способ увидеть их?

Кроме того, я не совсем понимаю, почему эти горячие точки не отображаются при выборе состояния «Работает». Более того, это опция по умолчанию...

Удивительно, но если я добавлю эти 4 верхних прошедших времени, это даст мне ~1h, но выполнение будет ~19min 20s, как если бы некоторые горячие точки перекрывались. Я думаю, что это побочный эффект опции «Все состояния».


java maven jprofiler
person superbob    schedule 18.06.2014    source источник
comment
Вы пытались установить селектор состояния потока в правом верхнем углу на все состояния?   -  person Ingo Kegel    schedule 18.06.2014
comment
@IngoKegel, спасибо за ваше предложение, я попробовал, пожалуйста, взгляните на мой EDIT 2:.   -  person superbob    schedule 19.06.2014
comment
В настоящее время единственным рабочим вариантом, который у меня есть, является запуск тестов по отдельности с помощью JUnit (без Maven) с использованием такой команды, как: java -agentpath:... -cp ... org.junit.runner.JUnitCore ‹path_to_my_test_class ›, таким образом я вижу полезную информацию в JProfiler, но имеет много недостатков (необходимо запускать каждый тест отдельно, не может иметь глобальных индикаторов, непрактичная командная строка...)   -  person superbob    schedule 19.06.2014
comment
Вы видите сумму прошедшего времени во всех потоках, поэтому, если у вас несколько потоков, это всегда больше, чем время настенных часов. Какие у вас настройки фильтра? Вы должны определить инклюзивные фильтры для ваших пакетов верхнего уровня.   -  person Ingo Kegel    schedule 20.06.2014
comment
Я нашел это, это трюк Maven: интеграционные тесты в maven выполняются на отдельной виртуальной машине. А MAVEN_OPTS в этой ВМ игнорируются. Решение состоит в том, чтобы настроить отказоустойчивый плагин для использования параметров jprofiler. При правильной настройке вижу полезные результаты в профилировании. Я напишу чистый ответ на свой вопрос, чтобы объяснить это.   -  person superbob    schedule 23.06.2014

Ответы (1)


arrow_upward
1
arrow_downward

Хитрость заключается в том, что Maven failsafe-плагин запускает интеграционные тесты в отдельном JVM :

Типичная сборка Maven с модульными тестами и интеграционными тестами может легко использовать 3 разных JVM:

  • Maven main JVM (compile, package), launched by the mvn command
    • Surefire JVM (unit tests), launched by the Maven main JVM
    • Отказоустойчивая JVM (интеграционные тесты), запущенная основной JVM Maven.

Профилирование основной JVM Maven никогда не покажет информацию о работе, проделанной внутри Failsafe JVM. Более того, параметры, указанные в MAVEN_OPTS, передаются только основной JVM Maven.

Чтобы профилировать одну из других JVM, вы должны настроить ее отдельно, используя конфигурацию плагинов в файле pom.xml.

Чтобы ответить на вопрос, требуется следующая конфигурация плагина:

<plugins>
    [...]
    <plugin>
        <artifactId>maven-failsafe-plugin</artifactId>
        <version>2.17</version>
        <executions>
            <execution>
                <goals>
                    <goal>integration-test</goal>
                    <goal>verify</goal>
                    <!-- to exclude IT from main build, comment the 'verify' goal -->
                </goals>
            </execution>
        </executions>
        <configuration>
            <argLine>${failsafeArgLine}</argLine>
        </configuration>
    </plugin>
    [...]
</plugin>

Важная часть здесь <argLine>${failsafeArgLine}</argLine>

Затем параметры агента JProfiler можно указать с помощью аргумента failsafeArgLine:

mvn verify -DfailsafeArgLine="-agentpath:/opt/jprofiler8/bin/linux-x64/libjprofilerti.so=port=8849"

Выполнение этой команды запустит сборку Maven в обычном режиме (без профилирования), а затем, когда начнется этап интеграционных тестов, будет запрошено соединение JProfiler:

[...]
[INFO] 
[INFO] --- maven-failsafe-plugin:2.17:integration-test (default) @ project ---
[INFO] Failsafe report directory: /home/user/Repositories/project/target/failsafe-reports

-------------------------------------------------------
 T E S T S
-------------------------------------------------------
JProfiler> Protocol version 39
JProfiler> Using JVMTI
JProfiler> JVMTI version 1.1 detected.
JProfiler> 64-bit library
JProfiler> Listening on port: 8849.
JProfiler> Instrumenting native methods.
JProfiler> Can retransform classes.
JProfiler> Can retransform any class.
JProfiler> Native library initialized
JProfiler> VM initialized
JProfiler> Waiting for a connection from the JProfiler GUI ...
JProfiler> Using dynamic instrumentation
JProfiler> Time measurement: elapsed time
JProfiler> CPU profiling enabled
[...]

Аргументы Failsafe VM также можно было указать непосредственно в файле pom.xml (вместо использования свойства failsafeArgLine), но я предпочитаю использовать его таким образом.

person superbob    schedule 23.06.2014