Java VisualVM дает странные результаты для профилирования процессора - кто-нибудь еще сталкивался с этим?

Question

Я написал этот небольшой (и крайне неэффективный) класс и хотел профилировать его с помощью Java VisualVM.

public class Test {

    public static void main(String[] args) throws IOException {
        BufferedReader br = new BufferedReader(new InputStreamReader(System.in));
        br.readLine();
        int n = Integer.parseInt(args[0]);
        int fib = fib(n);
        System.out.println(fib);
    }

    private static int fib(int n) {
        if (n < 2) {
            return n;
        }
        return fib(n-1)+fib(n-2);
    }
}

Результаты странные.В результатах преобладают вызовы ConnectionHandler.run ().

(98,2%) sun.rmi.transport.tcp.TCPTransport $ ConnectionHandler.run ()
(1,7%) java.lang.Thread.join (long)
(0%) java.lang.String.equals (Object)
etc ...

Вероятно, профилировано около ста методов, и ни один из них не являетсяfib (int)!

Невероятно, что моя программа фактически тратит все свое время на эти методы.Похоже, они подключаются к моему jvm и делают свое дело.

Что я делаю не так?

Отредактировано для ясности: Если передать 45 дляЭто приложение работает в течение 20 секунд.Изначально программа, которую я профилировал (не калькулятор Фибоначчи), привязывает все четыре ядра к моему процессору на 100%, и я выполнял профилирование продолжительностью до 5 минут.У них были те же результаты, и методы из моего приложения не появлялись высоко в списке методов горячих точек.

Это варьируется от запуска к запуску, но ConnectionHandler.run () всегда вверху и обычно составляет ~99% времени профиля.

Второе редактирование: Я попытался использовать сэмплер, и теперь я получаю результаты, которые согласуются с тем, что производит JProfiler.Недостатком этого является то, что я не получаю информацию трассировки стека, которая поставляется с профилированием.Но для моих насущных потребностей это отлично.

Что-то, что я обнаружил во время игры, - это то, что VisualVM подсчитывает время для вызовов методов во время их профилирования.

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

Это означает, что метод блокировки, по-видимому, займет почти всевремени на профилировщике, несмотря на тот факт, что не этот метод поглощает мой процессор.

Я ожидаю, что то же самое верно и для sun.rmi.transport.tcp.TCPTransport $ ConnectionHandler.Метод run (), который хорошо выполняет свою работу - но когда он завершается, он становится одним из самых продолжительных методов в моем приложении - несколько раз .

Answer 1

Я не думаю, что это вообще немыслимо.У вас есть приложение, в котором «полезная нагрузка» довольно крошечная (хотя это, конечно, зависит от значения n), и вы должны согласиться с тем, что потребовались дополнительные усилия (для подключения профилировщика и передачи всей информации к нему).) затопит эту полезную нагрузку.

Это не то приложение, которое я бы профилировал в первую очередь, так как совершенно очевидно, что огромное количество времени будет потрачено в fib в любом случае (для нетривиальногозначения n), отмечая это как очевидную цель для оптимизации.

Я был бы более склонен использовать профилировщик для более существенных приложений, где:

• не очевидно, гдеусилия по оптимизации должны идти;и
• в полезной нагрузке предстоит проделать значительный объем работы.

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

int fib = fib(n);

на:

for (int i = 0; i < 100000; i++) {
    int fib = fib(n);
)

---

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

Таким образом,Я имею в виду, что бинарный поиск является хорошим кандидатом, поскольку он удаляет половину оставшегося пространства поиска с каждым уровнем рекурсии (так что пространство поиска из миллиарда элементов составляет только 30 уровней).

С другой стороны, используя рекурсиюдля последовательности Фибоначчи с числом 1,000,000,000 потребуется около миллиарда уровней, и большинству стеков будет трудно это содержать.

Оптимизация рекурсии конца хвоста может избежать этой проблемы, но вы должны быть осторожны в случае, если оптимизация не требуется.не сделано.

Answer 2

На основании ответа Рона удалось улучшить результат, остановив JVM сразу после запуска, затем активировав профилировщик и, наконец, после этого продолжить исключение (нажав Enter). Это сыро.

class Foobar {
    /* First line in Class */
      static {
        try {
            System.in.read();
        } catch (IOException e) {
            throw new RuntimeException(e);
        }
    }
    /* .. */
    public static void main(..) {
        doMagic()
    }
}        

Answer 3

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

Переместите ваш метод fib в другой класс и попробуйте снова выполнить профилирование.Вы можете добавить опцию jvm "-verbose: class", чтобы дважды проверить, что класс не загружен, прежде чем включить профилирование процессора в jvisualvm.

Редактировать: Спасибо JB за комментарий.Забудь мою классную фигню.Моя интуиция заключается в том, что метод fib слишком тесно связан с основным методом, поэтому в настоящее время он фактически выполняется как байт-код.

Answer 4

Я предполагаю, что вы передаете слишком маленькое значение в fib, и программа просто не запускается достаточно долго для регистрации. Чтобы получить значимые данные для чего-либо практически при профилировании (или оценке производительности), вам обычно требуется время, по крайней мере, несколько секунд.