Устранение проблемы вероятностной массовой блокировки потока, вызванной ES-APM

JVM оптимизация производительности

Некоторое время назад мы подключили Elastic-APM производства ELK в качестве полнофункциональной платформы мониторинга, которая положила конец полнофункциональной платформе мониторинга внедрения байт-кода, которую я написал несколько лет назад. Некоторое время назад, в процессе запуска бизнеса, большое количество потоков было вероятностно заблокировано, в результате чего очень мало потоков HTTP, которые могут предоставлять услуги внешнему миру.После прихода трафика потоки HTTP были немедленно исчерпаны, Запрос интерфейса проверки работоспособности не удался, и служба была убита k8s.

анализ стека

Поскольку это проблема с потоками, конечно, на ум приходит дамп стека потоков, а также возможно чтение человеческой плоти.Загрузка в PerfMa XSheepdog будет проще. Скриншот этого столбца блокировки показан ниже.

Видно, что поток http-nio-18880-exec-44 содержит блокировку, ожидающую 199 других потоков. Стек потоков, удерживающий блокировку, показан на рисунке ниже.

Вызывающий метод верхнего уровня — co.elastic.apm.agent.bci.ElasticApmAgent#ensureInstrumented.За этой логикой стоит вызов bytebuddy для использования ASM для внедрения преобразования класса.

Поток, ожидающий блокировки, блокируется в этом методе, как показано на следующем рисунке.

Благодаря анализу стека возникновение этой проблемы связано с использованием ParallelStream в нашем бизнес-коде. Поток в Java — относительно простая в использовании штука, и его относительно просто написать в функциональном программировании и потоковой обработке данных. В дополнение к сериализованной потоковой обработке Java также предоставляет параллельные потоки. parallelStream может использовать многоядерную и многопоточную параллельную обработку, как показано на следующем рисунке.

Наш бизнес-код выглядит так:

private List<TaskRule> getTaskRules(Task task, List<TaskRule> taskRules) {
    return taskRules.parallelStream()
                   .filter(taskRule -> taskRule.getTaskId().equals(task.getId()))
                   .sorted(Comparator.comparing(TaskRule::getLower))
                   .collect(Collectors.toList());
}

Человек, стоящий за parallelStream, — это ForkJoin, который использует подход «разделяй и властвуй» для разбиения задач на небольшие задачи, а затем обеспечивает распараллеливание через пул потоков ForkJoinPool.

Чтобы обойти отслеживание ссылок между потоками, ES-APM внедряет классы, связанные с многопоточностью. Плагин apm-java-concurrent-plugin внедряет все подклассы ForkJoinTask. Многие классы, используемые в базовой реализации ForkJoin, наследуют ForkJoinTask. Например следующее:

  • java.util.stream.Nodes$CollectorTask
  • java.util.stream.Nodes$ToArrayTask$OfRef
  • java.util.stream.ReduceOps$ReduceTask
  • java.util.concurrent.CountedCompleter
  • ...

После запуска службы поступает большое количество HTTP-запросов для вызова метода getTaskRules, а потоки HTTP и потоки в ForkJoinPool будут вызывать код ES-APM, чтобы определить, были ли эти классы внедрены с помощью байт-кода. Код для ES-APM для определения того, был ли преобразован класс, выглядит следующим образом:

Приведенный выше код имеет очевидную проблему параллелизма. Логика здесь заключается в том, чтобы сначала запросить, был ли класс преобразован. Если нет, введите блокировку класса и выполните внедрение байт-кода связанного класса.

В случае высокого параллелизма поток HTTP и поток в ForkJoinPool вызывают метод getOrCreate.В это время, поскольку класс не был преобразован, возвращается пустой набор, и тогда один счастливчик захватывает блокировку класса ElasticApmAgent, и все остальные темы Все заблокированы.

Когда счастливчик закончит преобразование класса, следующий поток, захвативший блокировку класса, снова выполнит преобразование класса (ужасно). Другие, которые не были захвачены, будут продолжать блокироваться. Мало того, потому что потоки в пуле потоков ForkJoinPool также будут здесь заблокированы, что приведет к блокировке HTTP-запросов, и вскоре весь пул потоков tomcat будет исчерпан.

На этом еще не все.На самом деле если обработка очень быстрая то большой проблемы нет.Просто один и тот же класс будет усложняться каждый раз при перезаписи,и файл будет становиться больше.В следующий раз байткод класс впрыскивается в цветок дольше.

Используйте Артаса для внедрения BytebuddyAgentBuilder$Default$ExecutingTransformer.transformметод, сигнатура этого метода выглядит следующим образом.

private byte[] transform(JavaModule module,
                         ClassLoader classLoader,
                         String internalTypeName,
                         Class<?> classBeingRedefined,
                         ProtectionDomain protectionDomain,
                         byte[] binaryRepresentation) {
}

Где internalTypeName представляет имя класса для преобразования, а binaryRepresentation представляет последние данные байт-кода текущего преобразованного класса.

Запустите arthas и включите unsafe:

options unsafe true

Затем используйте команду watch для наблюдения за входными параметрами.

watch co.elastic.apm.agent.shaded.bytebuddy.agent.builder.AgentBuilder$Default$ExecutingTransformer transform   "{params}" -x 2

ts=2020-10-22 03:41:52; [cost=0.358887ms] result=@ArrayList[
    @Object[][
        null,
        null,
        @String[java/util/concurrent/CountedCompleter],
        @Class[class java.util.concurrent.CountedCompleter],
        null,
        @byte[][isEmpty=false;size=4379],
    ],
]
...
ts=2020-10-22 03:47:26; [cost=1021.689119ms] result=@ArrayList[
    @Object[][
        null,
        @String[java/util/concurrent/CountedCompleter],
        @Class[class java.util.concurrent.CountedCompleter],
        null,
        @byte[][isEmpty=false;size=88422],
    ],
]
ts=2020-10-22 03:50:27; [cost=1419.025166ms] result=@ArrayList[
    @Object[][
        null,
        @String[java/util/concurrent/CountedCompleter],
        @Class[class java.util.concurrent.CountedCompleter],
        null,
        @byte[][isEmpty=false;size=102910],
    ],
]

Видно, что класс CountedCompleter претерпел множество преобразований, от нескольких тысяч до более чем 100 тысяч, и преобразование будет продолжать увеличиваться, код становится все более сложным, а время для ASM для внедрения байт-кода будет становиться все больше и больше. , показывая явление:

  • Поток, удерживающий блокировку, тратит все больше и больше времени на преобразование класса.
  • Соответственно потоку, ожидающему блокировки, придется ждать дольше

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

[06:15:32][http-nio-18880-exec-49]done:class java.util.stream.Nodes$CollectorTask time:313	306
[06:15:33][http-nio-18880-exec-45]done:class java.util.stream.Nodes$ToArrayTask$OfRef time:496	233
...
[06:15:50][http-nio-18880-exec-17]done:class java.util.stream.Nodes$ToArrayTask$OfRef time:18317	1075
...
[06:16:54][http-nio-18880-exec-27]done:class java.util.stream.Nodes$ToArrayTask$OfRef time:81713	5481
...
[06:22:51][http-nio-18880-exec-59]done:class java.util.stream.Nodes$CollectorTask time:438733	24975
...

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

проверять

Чтобы подтвердить предыдущий процесс анализа, вы можете проверить ситуацию: есть только один запрос в первый раз, и нет параллелизма, вызванного пользователем, так что классы, связанные с параллелизмом, быстро внедряются и завершаются, а затем сделайте тест давления, чтобы увидеть, будут ли какие-либо проблемы. Действуйте следующим образом:

  • Первый шаг — дождаться запуска службы, использовать curl для запроса и сначала запросить интерфейс.
  • Затем используйте ab или jmeter, чтобы отчаянно нажать на этот интерфейс, чтобы увидеть, как интерфейс реагирует.

Результат ожидаемый, время отклика интерфейса нормальное, jstack проверяет стек на сцене, нет блокировки потока в ожидании блокировки класса ElasticApmAgent.

Решение

Самое простое решение — временно убрать parallelStream для бизнеса, а сначала обойти его, если есть ямы. Существует также незрелый метод модификации, и я не знаю, правильный он или нет: добавить строку перед вторым суждением, содержащимся в синхронизированном блоке, чтобы получить последнюю логику прикладных инструментов, как показано ниже, если она была преобразован, вы можете пропустить последнюю логику.

После переупаковки ES-APM для тестирования проблема в этом сценарии действительно решается.

резюме

Когда что-то пойдет не так, не сомневайтесь в себе, а смело сомневайтесь в фреймворке.В ES-APM есть классовая блокировка, которая вызывается супер часто, да и производительность ненамного лучше, да и места для улучшение. Ладно, с работы.

Категории