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

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

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

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

  • Коррелируйте логи Rails с помощью X-Request-Id.
  • Совместное использование X-Request-Id между несколькими приложениями Rails.
  • Поделитесь X-Request-Id с приложением базы данных.

Сопоставление журнала Rails, относящегося к одному запросу

По умолчанию журналы приложений Rails выглядят так, как показано ниже. Это относится только к одному запросу приложения, который является запросом GET /users:

Хотя журналы кажутся упорядоченными и все строки, принадлежащие запросу, связаны друг с другом, это не тот случай, когда приложение работает в производственной среде с многопоточными / многопроцессорными веб-серверами, такими как puma или unicorn. В этом случае несколько процессов / потоков будут записывать журналы, и нет гарантии, что каждый журнал запросов будет отображаться связанным вместе. Фактически, журналы от разных запросов будут перекрывать друг друга, и журналы в производственной системе могут выглядеть так, как показано ниже:

Из приведенного выше фрагмента очень сложно (если не невозможно) сказать, какая строка журнала принадлежит какому запросу. К счастью, Rails можно легко настроить для сопоставления строк журнала, принадлежащих одним и тем же запросам, с помощью ActionDispatch:RequestId промежуточного программного обеспечения. Это промежуточное ПО генерирует случайный уникальный идентификатор запроса или использует идентификатор запроса, переданный в заголовках запроса. Мы можем использовать этот идентификатор, чтобы пометить журналы Rails, чтобы сопоставить строки журнала Rails. Эту задачу можно выполнить, выполнив следующие изменения в исходном коде приложения Rails:

  • Добавление следующей строки либо к config/environments/${env}.rb, чтобы применить изменение к определенной среде (например, production), либо к config/application.rb, чтобы применить изменение ко всем поддерживаемым средам:
config.log_tags = [ :uuid ]

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

Это было легко изменить, но что, если мы захотим сопоставить журналы, принадлежащие разным приложениям? Можем ли мы использовать тот же идентификатор запроса?

Корреляция журналов между двумя приложениями Rails, которые взаимодействуют друг с другом синхронно

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

RequestHeaderMiddleware - это хранилище запросов, которое хранит все заголовки из белого списка (по умолчанию только X-Request-Id) и делает его доступным для запросов Rails на всех этапах. Поскольку хранилище доступно для исходного кода Rails глобально и содержит идентификатор запроса, можно использовать хранилище для извлечения идентификатора запроса из хранилища и передачи его в качестве заголовка запроса для всех исходящих запросов. Затем ActionDispatch:RequestId в службе назначения будет использовать переданное значение заголовка и не будет генерировать новый идентификатор запроса для этого запроса.

RequestHeaderMiddleware предоставляет инструкции по передаче идентификатора запроса другим службам с использованием ActiveResource, Faraday и JsonApiClient. Однако промежуточное ПО можно интегрировать / использовать с любым гемом или библиотекой, которые выполняют HTTP-запросы и предоставляют способ добавления заголовков HTTP-запросов. Ниже приведены изменения, необходимые для использования промежуточного программного обеспечения:

  • ActiveResource: приведенный ниже класс может использоваться как базовый класс для всех ActiveResource классов, реализованных в приложении. В результате пересылка заголовка будет выполнена без каких-либо дополнительных действий.
  • Faraday: Таким же образом мы можем создать глобальный одноэлементный объект Фарадея, который передает заголовок из RequestHeaderMiddleware с каждым исходящим запросом.
  • JsonApiClient: Согласно документации промежуточного программного обеспечения, передача заголовков для класса, расширенного с JsonApiClient, может выполняться с использованием синтаксиса ниже.

Следующим шагом будет поиск способа сопоставления журналов Rails с журналами базы данных. Было бы неплохо, если бы мы могли передать идентификатор запроса и в журналы базы данных.

Связывание журналов базы данных с журналами приложений Rails

Поскольку приложения баз данных, такие как MySQL, MongoDB и SqlServer, не являются приложениями Rails и не используют ActionDispatch:RequestId (фактически, они не принимают HTTP-запросы), невозможно просто пересылать заголовки этим службам.

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

2019-12-19T20:54:50.325378Z   2 Query SELECT `users`.* FROM `users`
2019-12-19T20:54:50.548397Z   2 Query SELECT `users`.* FROM `users`
2019-12-19T20:54:50.842785Z   2 Query SELECT `users`.* FROM `users`

К счастью, можно настроить приложения Rails для прикрепления комментариев к запросам SQL перед их отправкой на сервер базы данных. Прикрепленные комментарии можно увидеть в журналах сервера базы данных, показанных ниже:

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

Камень marginalia также позволяет разработчикам настраивать и расширять атрибуты комментариев. Гем предоставляет некоторые встроенные атрибуты, такие как атрибут строки, который может возвращать строку кода, сгенерировавшего запрос SQL.

Еще один шаг, который можно сделать здесь, - это включить идентификатор запроса в SQL комментарии, сгенерированные гемом marginalia. Эту задачу можно решить, используя RequestHeaderMiddleware для расширения комментариев на полях. Добавление инициализатора ниже в приложение Rails позаботится о добавлении атрибута request-id в список атрибутов, включенных в комментарии SQL.

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

Заключение

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