Представьте, endpoint на Quarkus иногда отвечает за секунды вместо миллисекунд. Как вы будете искать причину?

Первичная классификация: intermittent vs постоянный

Endpoint иногда отвечает за секунды — ключевое слово «иногда». Это сразу сужает круг причин: постоянные проблемы (плохой алгоритм, N+1) дают стабильно высокую latency. Intermittent spikes указывают на:

• исчерпание ресурса (connection pool, thread pool, GC pause);
• внешнюю зависимость с нестабильным временем ответа (база, Redis, внешний API);
• холодный старт (JVM JIT warm-up, lazy init CDI-бина);
• contention на общем ресурсе (lock, synchronized блок).

Шаг 1: Зафиксировать паттерн

Прежде чем что-то чинить — зафиксируйте, когда именно происходит spike:

# Смотрим на p99 latency в Prometheus
http_server_requests_seconds{uri="/api/endpoint", quantile="0.99"}

# Сколько запросов в очереди в момент spike
executor_queue_size{name="vert.x-worker-thread"}

# Активные соединения с БД
agroal_active_count
agroal_await_count

Если executor_queue_size резко растёт в момент spike — bottleneck в thread pool. Если agroal_await_count > 0 — bottleneck в DB connection pool.

Шаг 2: OpenTelemetry трейс конкретного медленного запроса

# application.properties
quarkus.otel.exporter.otlp.endpoint=http://tempo:4317
quarkus.otel.traces.sampler=parentbased_always_on

Откройте Jaeger/Grafana Tempo и найдите трейс с latency > 1s. Span breakdown покажет, где именно секунды — в SQL-запросе, HTTP-вызове к внешнему сервису или в самом handler-коде.

Шаг 3: Проверка BlockedThreadChecker

Quarkus Vert.x логирует предупреждение при блокировке I/O-потока:

# В логах ищем:
# WARN  [io.ver.cor.imp.BlockedThreadChecker] Thread Thread[vert.x-eventloop-thread-0,...]
# has been blocked for 2458 ms, time limit is 2000 ms
grep "BlockedThreadChecker" /var/log/app.log

Если такие строки есть — в handler выполняется блокирующий код (JDBC, синхронный HTTP-клиент) без @Blocking. Это блокирует event loop и все последующие запросы ждут освобождения потока.

Шаг 4: Анализ SQL через Hibernate statistics + slow query log

quarkus.hibernate-orm.statistics=true
quarkus.hibernate-orm.log.sql=true
quarkus.hibernate-orm.log.format-sql=true
# Логировать только медленные запросы (мс)
quarkus.hibernate-orm.log.queries-slower-than-ms=500

Также включите slow query log на уровне PostgreSQL:

-- В postgresql.conf или через ALTER SYSTEM
ALTER SYSTEM SET log_min_duration_statement = 500;  -- мс
SELECT pg_reload_conf();

Шаг 5: Профилирование с async-profiler

# Запустить 30-секундный CPU профиль
./asprof -d 30 -e cpu -f /tmp/cpu.html $(pgrep java)

# Или wall-clock (ловит waiting тоже)
./asprof -d 30 -e wall -t -f /tmp/wall.html $(pgrep java)

Wall-clock профиль особенно полезен для intermittent спайков — он показывает потоки в состоянии WAITING и TIMED_WAITING, что указывает на lock contention или ожидание пула.

Шаг 6: GC паузы

# Включить GC логи в JVM
JAVA_OPTS="-Xlog:gc*:file=/tmp/gc.log:time,uptime:filecount=5,filesize=10m"

# Смотрим паузы Stop-The-World
grep "Pause Full\|Pause Young" /tmp/gc.log | awk '{print $NF}'

Если паузы совпадают с моментами spike по времени — проблема в GC. Решение: увеличить heap (-Xmx), переключиться на ZGC (-XX:+UseZGC), или найти источник allocation pressure.

Шаг 7: Воспроизвести локально под нагрузкой

# k6 — нагрузочный тест для воспроизведения
k6 run --vus 50 --duration 60s - <<EOF
import http from 'k6/http';
export default function() {
  http.get('http://localhost:8080/api/endpoint');
}
EOF

Подводные камни

• JIT warm-up маскирует реальную проблему: первые несколько сотен запросов к JVM-приложению всегда медленнее из-за JIT-компиляции. Измеряйте latency после прогрева.
• Connection pool по умолчанию мал: Agroal по умолчанию имеет max-size=20. При 50 concurrent запросах к БД 30 будут ждать в очереди.
• Lazy initialization CDI-бинов: @ApplicationScoped создаёт proxy лениво — первый запрос к бину инициализирует его и может занять время (например, при инициализации HTTP-клиента с DNS lookup).
• Трейсы с sampling пропускают медленные запросы: если используете rate-based sampling, редкие спайки могут не попасть в выборку — используйте tail-based sampling или временно включите always_on.
• Wall-clock профиль влияет на производительность: async-profiler с -e wall имеет overhead ~5% — запускайте в production только на короткое время.
• Медленный внешний API скрывается за таймаутом: если у HTTP-клиента нет таймаута, зависший внешний вызов держит worker thread до дефолтного таймаута ОС (минуты). Всегда устанавливайте connect-timeout и read-timeout явно.
• Lock contention в бизнес-логике: synchronized-блоки или ReentrantLock в shared-сервисах под нагрузкой дают резкие спайки. Flamegraph покажет потоки в BLOCKED-состоянии.
• Dev Services в тестах не равны production: Testcontainers-база в dev-mode работает иначе, чем production PostgreSQL с pgbouncer. Всегда воспроизводите проблему на staging с реальным трафиком.

• Сразу обвинять Quarkus, не проверив соседние слои системы
• Чинить симптом без минимального воспроизведения и evidence
• Не учитывать версии, конфигурацию, окружение и recent changes

• Умеет локализовать проблему вокруг Quarkus
• Двигается от симптома к гипотезам и проверкам
• Отличает баг инструмента от ошибки использования или окружения