Приложение Spring Boot зависает при использовании виртуальных потоков на Java 21

Я столкнулся с проблемой, связанной с производительностью приложения Spring Boot 3 с включенными виртуальными потоками.

Этапы воспроизведения TL;DR:

  1. Оформить заказ https://github.com/stsypanov/concurrency-demo
  2. Запустите DependencyApplication и ConcurrencyDemoApplication
  3. Когда оба приложения запущены StuckApplicationTest
  4. Для завершения теста потребуется около 1-2 минут.
  5. Теперь перейдите к demo-service/application.yml и установите spring.threads.virtual.enabled: true (по умолчанию это false).
  6. Перезагрузить ConcurrencyDemoApplication
  7. Беги StuckApplicationTest еще раз
  8. Запустите YourKit профилировщик и подключитесь к ConcurrencyDemoApplication, почти сразу вы увидите предупреждающее сообщение о потенциальной тупиковой ситуации, а само приложение зависнет, поскольку все потоки его ForkJoinPool имеют Waiting статус.

Более подробное описание:

Общая установка:

  • Windows 11
  • Intel(R) Core(TM) i7-1370P 13-го поколения
  • Либерика JDK 21.0.4
  • Весенняя загрузка 3.3.2
  • org.springframework.cloud:spring-cloud-dependencies:2023.0.3
  • io.github.openfeign:feign-httpclient

Чтобы воспроизвести проблему, вам нужен тест, выполняющий не так много одновременных вызовов микросервиса на основе Spring Boot, например. звоню /actuator/health:

@Test
void run() {
    var restTemplate = new RestTemplate();
    var latch = new CountDownLatch(1);
    var executor = Executors.newVirtualThreadPerTaskExecutor();
    try (executor) {
        for (int i = 0; i < 100; i++) {
            executor.submit(() -> {
                waitOn(latch);
                assertNotNull(restTemplate.getForEntity("http://localhost:8081/actuator/health", ResponseEntity.class));
            });
        }
        latch.countDown();
    }
    assertTrue(executor.isTerminated());
}

private static void waitOn(CountDownLatch latch) {
    try {
        latch.await();
    } catch (InterruptedException e) {
        throw new RuntimeException(e);
    }
}

Этот тест отправляет GET-запросы, скажем, на Service A. В Service A у меня есть довольно простой экземпляр HealthIndicator и клиента Feign:

@Component
@RequiredArgsConstructor
public class DownstreamServiceHealthIndicator implements HealthIndicator {
    private final HealthClient healthClient;

    @Override
    public Health health() {
        var response = healthClient.checkHealth();
        if (response.getStatusCode().is2xxSuccessful()) {
            return new Health.Builder().up().build();
        }
        return new Health.Builder().down().withDetails(Map.of("response", response)).build();
    }
}

@FeignClient(name = "healthClient", url = "http://localhost:8087/actuator/health", configuration = InternalFeignConfiguration.class)
public interface HealthClient {
    @GetMapping
    ResponseEntity<String> checkHealth();
}

public class InternalFeignConfiguration {
    @Bean
    public Client client() {
        return new ApacheHttpClient(HttpClients.createDefault());
    }
}

Опять же, тест одновременно вызывает /actuator/health из Service A через RestTemplate и Service A вызывает /actuator/health из Service B через клиент Feign. Service B состоит из основного класса приложения и application.yml (см. код в указанном выше репозитории), объявляющего конечную точку работоспособности.

Когда вы запускаете систему с настройками по умолчанию, все в порядке. Для завершения теста требуется ~1,5 секунды, но все остальное в порядке.

Однако при включенных виртуальных потоках Service A зависает, и если вы подключаетесь к нему, например. В профилировщике YourKit вы получите предупреждающее сообщение о потенциальной тупиковой ситуации с помощью этой трассировки стека:

+-----------------------------------------------------------------------------------------------------------------------------+
|                                                            Name                                                             |
+-----------------------------------------------------------------------------------------------------------------------------+
|  +---Read-Updater Frozen for at least 10s <Ignore a false positive>                                                         |
|  | +---jdk.internal.misc.Unsafe.park(boolean, long) Unsafe.java (native)                                                    |
|  | +---java.util.concurrent.locks.LockSupport.park() LockSupport.java:371                                                   |
|  | +---java.util.concurrent.LinkedTransferQueue$DualNode.await(Object, long, Object, boolean) LinkedTransferQueue.java:458  |
|  | +---java.util.concurrent.LinkedTransferQueue.xfer(Object, long) LinkedTransferQueue.java:613                             |
|  | +---java.util.concurrent.LinkedTransferQueue.take() LinkedTransferQueue.java:1257                                        |
|  | +---sun.nio.ch.Poller.updateLoop() Poller.java:286                                                                       |
|  | +---sun.nio.ch.Poller$$Lambda.0x0000024081474670.run()                                                                   |
|  | +---java.lang.Thread.runWith(Object, Runnable) Thread.java:1596                                                          |
|  | +---java.lang.Thread.run() Thread.java:1583                                                                              |
|  | +---jdk.internal.misc.InnocuousThread.run() InnocuousThread.java:186                                                     |
|  |                                                                                                                          |
|  +---spring.cloud.inetutils Frozen for at least 10s <Ignore a false positive>                                               |
|  | +---java.net.Inet6AddressImpl.getHostByAddr(byte[]) Inet6AddressImpl.java (native)                                       |
|  | +---java.net.InetAddress$PlatformResolver.lookupByAddress(byte[]) InetAddress.java:1225                                  |
|  | +---java.net.InetAddress.getHostFromNameService(InetAddress, boolean) InetAddress.java:840                               |
|  | +---java.net.InetAddress.getHostName(boolean) InetAddress.java:782                                                       |
|  | +---java.net.InetAddress.getHostName() InetAddress.java:754                                                              |
|  | +---org.springframework.cloud.commons.util.InetUtils$$Lambda.0x0000024081187240.call()                                   |
|  | +---java.util.concurrent.FutureTask.run() FutureTask.java:317                                                            |
|  | +---java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker) ThreadPoolExecutor.java:1144            |
|  | +---java.util.concurrent.ThreadPoolExecutor$Worker.run() ThreadPoolExecutor.java:642                                     |
|  | +---java.lang.Thread.runWith(Object, Runnable) Thread.java:1596                                                          |
|  | +---java.lang.Thread.run() Thread.java:1583                                                                              |
|  |                                                                                                                          |
|  +---Write-Updater Frozen for at least 10s <Ignore a false positive>                                                        |
|    +---jdk.internal.misc.Unsafe.park(boolean, long) Unsafe.java (native)                                                    |
|    +---java.util.concurrent.locks.LockSupport.park() LockSupport.java:371                                                   |
|    +---java.util.concurrent.LinkedTransferQueue$DualNode.await(Object, long, Object, boolean) LinkedTransferQueue.java:458  |
|    +---java.util.concurrent.LinkedTransferQueue.xfer(Object, long) LinkedTransferQueue.java:613                             |
|    +---java.util.concurrent.LinkedTransferQueue.take() LinkedTransferQueue.java:1257                                        |
|    +---sun.nio.ch.Poller.updateLoop() Poller.java:286                                                                       |
|    +---sun.nio.ch.Poller$$Lambda.0x0000024081474670.run()                                                                   |
|    +---java.lang.Thread.runWith(Object, Runnable) Thread.java:1596                                                          |
|    +---java.lang.Thread.run() Thread.java:1583                                                                              |
|    +---jdk.internal.misc.InnocuousThread.run() InnocuousThread.java:186                                                     |
+-----------------------------------------------------------------------------------------------------------------------------+

Как следует из вышеизложенного, узкое место приложения находится в этом методе:

// class org.springframework.cloud.commons.util.InetUtils

public HostInfo convertAddress(final InetAddress address) {
    HostInfo hostInfo = new HostInfo();
    Future<String> result = this.executorService.submit(address::getHostName); // <---

    String hostname;
    try {
        hostname = result.get(this.properties.getTimeoutSeconds(), TimeUnit.SECONDS); // <---
    }
    catch (Exception e) {
        this.log.info("Cannot determine local hostname");
        hostname = "localhost";
    }
    hostInfo.setHostname(hostname);
    hostInfo.setIpAddress(address.getHostAddress());
    return hostInfo;
}

и основная причина, скорее всего, будет SingleThreadExecutor использоваться для определения имени хоста при удаленном вызове:

public InetUtils(final InetUtilsProperties properties) {
    this.properties = properties;
    this.executorService = Executors.newSingleThreadExecutor(r -> {
        Thread thread = new Thread(r);
        thread.setName(InetUtilsProperties.PREFIX);
        thread.setDaemon(true);
        return thread;
    });
}

На практике это означает, что одновременно может выполняться только одна задача, т. е. когда параллельные потоки выполняют одновременные вызовы, они разрешают имя хоста последовательно!

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

Может ли кто-нибудь объяснить, верна ли моя теория о основной причине проблемы и почему приложение, как ни странно, выживает в платформенных (тяжеловесных) потоках и умирает в виртуальных (т. е. облегченных) потоках?

В вашем тесте вы создаете 100 потоков, ожидающих одного и того же CountDownLatch, но вызываете latch.countDown(); только один раз. Значит, 99 потоков будут ждать вечно?

J Asgarov 25.07.2024 08:15

Нет, CountDownLatch здесь своего рода барьер: он создается с count = 1, и когда я это делаю, latch.countDown() все потоки, заблокированные в latch.await(), освобождаются и начинают отправлять запросы одновременно.

Sergey Tsypanov 25.07.2024 08:43
Пользовательский скаляр GraphQL
Пользовательский скаляр GraphQL
Листовые узлы системы типов GraphQL называются скалярами. Достигнув скалярного типа, невозможно спуститься дальше по иерархии типов. Скалярный тип...
Как вычислять биты и понимать побитовые операторы в Java - объяснение с примерами
Как вычислять биты и понимать побитовые операторы в Java - объяснение с примерами
В компьютерном программировании биты играют важнейшую роль в представлении и манипулировании данными на двоичном уровне. Побитовые операции...
Поднятие тревоги для долго выполняющихся методов в Spring Boot
Поднятие тревоги для долго выполняющихся методов в Spring Boot
Приходилось ли вам сталкиваться с требованиями, в которых вас могли попросить поднять тревогу или выдать ошибку, когда метод Java занимает больше...
Полный курс Java для разработчиков веб-сайтов и приложений
Полный курс Java для разработчиков веб-сайтов и приложений
Получите сертификат Java Web и Application Developer, используя наш курс.
6
2
160
1
Перейти к ответу Данный вопрос помечен как решенный

Ответы 1

Ответ принят как подходящий

Моё первое предположение оказалось неверным, эта тема не про InetUtils. Частично это проблема библиотеки, частично проблема JDK.

Запустив приложение с помощью -Djdk.tracePinnedThreads=full, я получил трассировку стека закрепленных тредов, она довольно длинная и доступна на https://github.com/stsypanov/concurrency-demo/blob/master/pinned-threads.txt.

Там обратите внимание на строки 12 и 92:

12 org.apache.http.pool.AbstractConnPool.getPoolEntryBlocking(AbstractConnPool.java:319)
92 org.apache.http.pool.AbstractConnPool.getPoolEntryBlocking(AbstractConnPool.java:391)

Исследуя трассировку стека, мы обнаруживаем, что в конечном итоге потоки застревают в пуле соединений org.apache.http.pool.AbstractConnPool, используемом org.apache.http.impl.client.InternalHttpClient.

Пул может быть создан только с maxTotal = 20 (максимальное количество соединений), для меня это ошибка, но в любом случае по умолчанию ForkJoinPool Tomcat построен с параллелизмом (т. е. числом потоков носителя) 20, поэтому давайте проверим, выживет ли приложение с меньшее количество соединений. В StuckApplicationTest мы уменьшили количество потоков до 20, и действительно, тесты больше не зависают, даже если на стороне сервера включены виртуальные потоки.

Теперь эта часть ясна, поэтому, если вы столкнетесь с тем же препятствием, вам нужно либо использовать HTTP-клиент feign по умолчанию, либо перейти на org.apache.httpcomponents.client5:httpclient5.

Но почему один и тот же код работает с потоками платформы? Я задал этот вопрос в списке рассылки loom-dev и получил ответ.

Как упомянул Алан Бейтман :

Далее в стеке находится AbstractConnPool.get с синхронизированным блоком, который вызывает здесь проблему. Ограничением на данный момент является то, что виртуальный поток не может отключиться внутри синхронизированного оператора или метода. В этом случае создается впечатление, что все операторы связи закреплены виртуальными потоками, которые заблокированы в одном и том же месте. Другое краткосрочное решение — перенести этот код на использование блокировки j.u.concurrent.

Ведется работа по снятию этого ограничения. Доступны сборки EA, которые мы нуждаемся в помощи в тестировании, прежде чем изменения будут предложены для основной линейки и будущего выпуска JDK.

Вот фрагмент с ошибкой AbstractConnPool:

@Override
public E get(final long timeout, final TimeUnit timeUnit) {
  for (;;) {
    synchronized (this) { // here we cannot unmount VT
      try {
        final E leasedEntry = getPoolEntryBlocking(); // here VT are blocked
        return leasedEntry;
      } catch (final IOException ex) {}
    }
  }
}

Я проверил сборку EAP из https://jdk.java.net/loom/, запустил на ней приложение, и теперь оно не зависает :)

Я не единственный, кто сталкивается с проблемами, воспроизводимыми с помощью VT (см., например, https://mail.openjdk.org/pipermail/loom-dev/2024-July/006939.html), поэтому я надеюсь, что это поможет для решения подобных проблем.

Другие вопросы по теме