Есть в профилировании JVM сложная задача — посчитать количество итераций в каждой строке за счет наложения на данные семплирующего профайлера (Sampling) данные трассировки (Tracing) и подсчета количества выполнений (Call counting)

Режим Sampling
дает самые меньшие искажения и почти незаметен для профилируемого сервиса, по нему можно понять, что какая-то строка кода выполняется, например, 60% времени

По данным семплирования удобно строить Flame диаграммы, как на скриншоте

И данная строка может быть горячей по разным причинам:
🤩медленная операция которая потребляет CPU
🤩выделяет память
🤩походы на диск
🤩походы по сети
🤩и может быть это супер быстрый код, но который вызывают 1 000 000 раз в цикле

Вот в этом последнем варианте причина медленной работы в том методе который вызывает данный метод 1 000 000 раз

Это довольно частый случай. А технически задача становится такой:
🤩собрать статистику по количеству выполнений методов
🤩наложить статистику с количеством на данные семплирования

Сбор статистики по количеству выполнений бывает двух видов
🤩без номеров строк и вышестоящих запросов (Call Counting) — быстрый
🤩с номерами строк (Tracing) — медленный

В Call Counting попадают абсолютно все вызовы данного метода, и если метод — это некий популярный интерфейс, как EntityIteratorBase.hasNext, то по нему будут миллионы вызовов в статистике, даже если в профилируемой операции он вызывался 10 000 раз только. Обычно такие методы в начале или середине стека. Они есть при каждом HTTP-запросе и каждой операции и Call Counting покажет для них очень высокие значения.

Но вот для уникальных строк в конце стек-трейса, таких как Delegator.checkPage (вершина Flame graph), Call Counting будет работать очень точно. Он покажет точные значения. Потому что чаще всего это узкое место уникально для этого запроса. А еще будут точные значения про метод который вызывал этот метод. И может быть про предыдущий

Как понять, что числа в Call Counting более менее настоящие

Например, смотрим на метрики сверху вниз

🤩DataIterator.checkPage — 27 000 000 вызовов
🤩PatriciaTreeBase.getDataIterator — 5 000 000 вызовов (такое может быть, этот метод вызывает checkPage примерно по 5-6 раз)
🤩PatriciaTreeBase.getLoggable — 5 000 000 вызовов (такое может быть, он вызывает getDataIterator только один раз)
🤩PatriciaTreeBase.loadNode — 5 000 000 (ok)
🤩ChildReference.getNode - 1 600 000 (этот вызывает loadNode 3 раза)
🤩PatriciaTraverser.moveDown — 80 000 000

Тут я выдумал число 80 000 000 для сокращения, но если вдруг количество по вышестоящему методу резко выроcло, а не упало — то это означает, что дальше метрикам Call Counting верить нельзя. Они свое отработали, показали для методов нижнего уровня сколько вызовов приходится на следующий:
🤩x5, x1, x1, x1, x3, x???

Дальше можно продолжать разматывать стек, но уже держа в голове, что это замусоренные данные.

И в какой-то момент придется переключиться на данные трассировки. Это самые неточные данные. Трассировка хоть и самая детальная, но вносит столько изменений и замедлений в код, что часто выполнение кода становится уже неполным (завершается по таймауту) или искаженным. Она покажет неполные данные — например скачок в x218208 на данных трассировки в реальности может быть и скачком в x1000000, но код просто не дожил то итерации в 1 000 000 и прервался на 218208. Но это лучшая оценка

Все такие множители удобно записывать в виде комментариев к строкам стек-трейса — просто через //

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

Год назад начал разбирать Memory Leak при просмотре результатов теста во View Result Tree, для случая больших файлов в запросах или ответах

Это задача 6336, разобрал тогда в какие моменты выделяется память и что она не очищается даже после Clear All.
Автор дефекта получил проблему на больших запросах (Request), а я проверял на ответах (Response)

Некоторые наблюдения из этого разбора
🤩тема System работает на 2 минуты быстрее темы Darklaf - Dracula (detault) при открытии результатов теста с большими файлами
🤩настройки на лимиты размеров текста при отображении, не делают объем хранимиго в памяти текста меньше — думаю что можно оставлять только начало ответа еще при загрузке результатов
🤩дедупликация строк не используется, если открыть два одинаковых ответа или запроса, то память выделится тоже дважы

Тут я говорю про настройки JMeter

## MAX_DISPLAY_SIZE
view.results.tree.max_size=10485760

## MAX_LINE_SIZE
view.results.tree.max_line_size=110000

## SOFT_WRAP_LINE_SIZE
view.results.tree.soft_wrap_line_size=100000

И настройку OpenJDK

## Дудупликация строк
-XX:+UseStringDeduplication

## Работает с G1GC:
-XX:+UseG1GC

## Сколько поколений сборки мусора надо пережить (3 по умолчанию)
-XX:StringDeduplicationAgeThreshold=1

## Надо будет добавить 100ms к длительности пауз (по умолчанию в JMeter 100)
-XX:MaxGCPauseMillis=200

Этот гештальт пока висит незакрытым. Вот думаю что пора его закрыть.

🤩Докрутить задачу с утечкой памяти именно для больших запросов.
🤩Сделать так чтобы в памяти ViewResultTree читались только первые
view.results.tree.max_size=10485760 байт, если результат загружается из файла (при просмотре результатов в live-режиме обрезать результат нельзя)
🤩исследовать есть ли лимит на отображение тела запроса (не только ответы могут быть большими)
🤩возможно обосновать, что красивая и темная Darklaf - Dracula тема слишком медленная и вернуться к System, как варианту по умолчанию
🤩добавить явное указание String.intern() для некоторых больших строк (думаю это точно нужно только для JMX-файлов и для тел запроса в режиме чтения тела запроса из файла
🤩включить по умолчанию UseStringDeduplication и подтянуть настройки G1GC так, чтобы дедупликация эффективно работала
🤩разобраться почему Clean All не приводит к освобождению памяти во View Result Tree

Задача вроде простая и короткая на входе. Но работы там зарыто немало. Да и на работе в YouTrack задачи примерно такие же, если не в 10 раз сложнее, и надо их разбирать первым приоритетом

Но если начать сообща разбирать дефект по дефекту, то разберем. Что думаете?

Представьте, что вы отвечаете за доступность и корректность работы большой системы, и у вас может быть есть явная роль SRE. Но вы так хорошо работали, что нет ни алертов ни проблем

Или вы запустили тест производительности, а он прошел хорошо, также как обычно, и даже никаких дефектов не завести ...

... кажется, что не завести никаких дефектов

На этот случай рекомендую открыть логи и посмотреть на их количество. Моя любимая фича в хранилище логов OpenSearch это Top 5 values по ключевым полям логов. А любимые поля это

🤩service, чтобы отфильтровать по сервису
🤩source или file, чтобы выбрать конкретный лог, если сервис пишет несколько логов
🤩level, чтобы оставить ERROR или WARN
🤩class (иногда это называется logger)
🤩message с текстом сообщения

Обычно достаточно сделать фильтры по
🤩service = главный сервис
🤩source = основной лог
🤩level = ERROR
и посмотреть на TOP-5 по полю
🤩class

Потом можно сделать фильтрацию только по TOP-1 значению, получить messages от этого класса, часто они будут очень похожи друг на друга. И тут вы сможете понять, что вот она ошибка, скрывалась, но нашлась

Такие удобные фильтры как TOP 5 values есть и OpenSearch Dashboard и в Kibana и в Grafana

Ни теста без дефекта!!