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

Сложно поверить?

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

Но прежде чем мы начнем, примеры кода также можно найти в нашем репозитории GitHub: https://github.com/dxfrontiers/coroutines-vs-reactive.

Отдельные решения реализованы в виде отдельных веток в репозитории. Просто взгляните!

Следы стека прямо из ада

В нашем примере приложения у нас есть типичная трехуровневая архитектура с веб-уровнем, сервисным уровнем и уровнем сохраняемости.

Я скорректировал вызов постоянства, чтобы сохранение объекта не удавалось глубоко в слое постоянства, создавая удивительно реалистичную трассировку стека.

Императивный вариант

Давайте сначала выясним, как будет выглядеть трассировка стека, используя обычную реализацию блокировки с помощью Spring MVC и Spring Data JPA:

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

Вызов метода CharacterRepository.save терпит неудачу, потому что идентификатор дома, на который указывает ссылка, не существует, что дает нам приятное исключение:

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

Как насчет реактивной реализации?

Реактивный вариант

Здесь мы используем Spring WebFlux для веб-части и Spring Data R2DBC для сохраняемости, что делает наше приложение полностью реактивным вплоть до сохраняемости:

Процедура примерно такая же. Контроллер делегирует вызов сервисному уровню:

Затем служба пытается сохранить сущность, но при этом терпит неудачу. Сгенерированная трассировка стека имеет колоссальные 166 строк. Я попытался отфильтровать соответствующие элементы. Но и это мало помогает:

Мы видим какие-то FluxSwitchIfEmpty, MonoFlatMap, FluxOnErrorResume вверху, хорошо… но это всего лишь некоторые операторы где-то в реактивной цепочке. В очень небольшой базе кода теперь мы могли бы сузить ошибку до конкретного вызова метода. В большей кодовой базе это, вероятно, будет невозможно.

И что еще более важно, во всей трассировке стека мы не находим ни одного вызова нашего метода, который мог бы привести нас к неудачному вызову метода save. Они просто испарились в пустоту.

Но почему это так? Почему трассировки стека в реактивных цепочках такие раздутые и их трудно анализировать? Чтобы ответить на этот вопрос, позвольте мне представить вам три этапа реактивного конвейера:

  • Этап сборки
  • Этап подписки
  • Этап выполнения

Реактивное программирование строго разделяет объявление и выполнение наших строк кода. Когда мы записываем наш реактивный конвейер, мы определяем, какие шаги выполнять, а не когда их выполнять. Это называется этап сборки. Мы связываем отдельные вызовы, и в конце у нас остается издатель (Mono или Flux), на который мы можем подписаться. Пока мы этого не сделаем, ничего не произойдет. Вы можете попробовать это, опустив «подписаться» в конце реактивной цепочки. Только при подписке на реактивный конвейер предоставляется контекст выполнения, а планировщики заботятся о следующих шагах за кулисами.

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

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

И здесь возникает проблема. Трассировка стека — это представление состояния среды выполнения. В асинхронном программировании это не обязательно соответствует порядку, в котором мы изначально написали код. Эта часть информации доступна только во время во время сборки. К счастью, фреймворк Reactor дает нам несколько возможностей компенсировать это несоответствие. В следующих разделах я продемонстрирую их на коротких примерах.

Отладка Printf

Наиболее эффективным средством отладки по-прежнему является тщательное обдумывание в сочетании с разумно размещенными операторами печати.

Вернуться к истокам! Брайан Кернигам однажды написал эту цитату в своей статье «UNIX для начинающих» в 1979 году. Следующая техника, вероятно, наиболее близка к тому, что многие знают как «отладка printf».

Reactor Framework предлагает для этого два основных варианта:

  • бревно()
  • сделатьПриОшибке()

бревно()

При добавлении log() к реактивному конвейеру все возникающие реактивные сигналы будут регистрироваться. Мы можем добавить параметр категории, чтобы жестко закодировать (в лучшем случае уникальную) белую метку для вызова, чтобы мы могли искать эту метку в выводе регистратора:

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

Первые три строки новые. Они показывают нам, что реактивная цепочка отправила всего три сигнала: начальную подписку (onSubscription), запрос на начало обработки данных (запрос) и завершение ошибки. сигнал (onError).

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

сделатьПриОшибке()

Этот метод можно добавить в реактивный конвейер в определенных точках, где мы ожидаем, что вызовы могут завершиться ошибкой. В нашем случае это, скорее всего, будет обращение к сервисному слою:

В отличие от операторов, таких как onErrorResume, doOnError не обрабатывает исключение, а просто добавляет некоторый побочный эффект, который выполняется всякий раз, когда сообщается об ошибке:

Здесь мы получаем некоторую дополнительную информацию о заданных параметрах для вызова REST, но возможности также относительно ограничены.

Здравствуйте, оператор, пожалуйста, дайте мне номер девять.

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

onOperatorDebug()

Эта опция позволяет нам активировать так называемый «режим отладки» с помощью настройки Hooks.onOperatorDebug(). Предпочтительно это устанавливается на этапе инициализации приложения один раз и как можно раньше. В приложении Spring Boot это можно сделать, вызвав его в методе main, даже до начальной загрузки приложения Spring:

Это активирует режим отладки Reactor для всего приложения. Это позволяет регистратору стека, который фиксирует каждое взаимодействие с реактивными операторами. Кроме того, он восстанавливает трассировку стека по порядку, также захватывая стек объявлений при создании экземпляра оператора. Это огромно.

Если мы добавим ловушку оператора, мы получим следующий дополнительный вывод помимо исходной трассировки стека и сообщения об ошибке:

Как мы видим, весь поток выполнения реконструирован. Мы видим вызов персистентности в строке 9 и вызов нашего сервиса в строке 10. Оператор switchIfEmpty в строке 11 был передан, и мы не перехватили и не обработали исключение в onErrorResume в строке 12, потому что мы обрабатываем только CharacterNotFoundException . Поэтому исключение распространяется вверх, пока оно не будет обработано в ExceptionHandlingWebHandler Spring WebFlux напрямую.

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

контрольно-пропускной пункт()

В принципе, onOperatorDebug() и checkpoint() — это одно и то же, за исключением того, что checkpoint() нужно явно добавлять к интересующим конвейерам. Например, если мы ожидаем, что метод addCharacter иногда будет давать сбой, мы можем добавить контрольную точку в конце, чтобы любые исключения, инициированные восходящим потоком, отражались в трассировке сборки:

Вызов оператора контрольной точки был добавлен в реактивную цепочку в строке 14. Это добавит заданное описание в трассировку сборки, потенциально помогая команде разработчиков выяснить, где произошла ошибка:

Собственно, здесь мы видим в логах четыре чекпойнта. Причина этого в том, что Spring WebFlux и Spring Data R2DBC уже добавляют контрольные точки на разных уровнях обработки для обогащения сообщения об ошибке.

Преимущество checkpoint() по сравнению с onOperatorDebug заключается в почти полном отсутствии накладных расходов на производительность. Однако мы должны сами добавлять контрольные точки в реактивную цепочку, и прирост информации также весьма ограничен.

Вы слышите это? Это звук неизбежности!

Давайте перейдем к последнему инструменту для отладки в этом сообщении блога.

Я уже говорил «Святая ручная граната»? ReactorDebugAgent, по крайней мере, находится на одном уровне, просто без потери производительности при захвате трассировки стека при каждом вызове оператора. Для этой цели ReactorDebugAgent использует инструментарий байт-кода сайта вызова, обогащая байт-код дополнительной информацией.

Например, следующий фрагмент кода:

превращается в:

Поскольку захват трассировки стека здесь полностью опущен, этот подход является относительно легким. Все, что вам нужно сделать, это добавить следующую зависимость в вашу сборку:

И снова инициализируйте ReactorDebugAgent как можно раньше, например в методе main:

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

Теперь, когда мы добавили ReactorDebugAgent, мы получим следующий вывод для нашего примера:

Как и раньше с Hooks.onOperatorDebug, мы можем очень хорошо проследить поток выполнения, за исключением того, что на этот раз мы видим еще больше промежуточных шагов. Просто проверьте это сами!

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

Операторы log и doOnError полезны для регистрации специально выбранных точек выполнения. Они не могут реконструировать поток данных, а скорее обогащают журналы, распечатывая параметры вызова, промежуточные преобразования данных или другую ценную информацию. ReactorDebugAgent, операторский режим отладки через Hooks.onOperatorDebug и контрольные точки фактически обогащают саму трассировку стека различной степенью информации. ReactorDebugAgent и оператор контрольной точки, безусловно, подходят для использования без колебаний даже в производственной среде. Hooks.onOperatorDebug следует использовать только на этапе активной разработки из-за повышенного потребления ресурсов для захвата стека объявлений и всех взаимодействий с реактивными операторами.

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

Спасибо за прочтение! Не стесняйтесь комментировать или сообщение мне, когда у вас есть вопросы или предложения. Вас могут заинтересовать другие посты, опубликованные в Блоге Digital Frontiers, анонсированные в нашем аккаунте Twitter.