Серия наблюдений микросервисов

Наблюдаемость микросервиса - журналы

Осмысление всего, что происходит в ваших журналах

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

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

Что и как вести журнал

Давайте возьмем пример системы электронной коммерции и посмотрим на регистрацию в Службе управления заказами (OMS).

Предположим, заказ клиента не выполнен из-за ошибки службы управления запасами (IMS), последующей службы, которую OMS использует для проверки доступных запасов.

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

404 Product Not Available

Что записывать

Обычно вы регистрируете ошибку таким образом

log.error(“Exception in fetching product information - {}”, ex.getResponseBodyAsString())

Будет выведен журнал в следующем формате

[2020-09-27T18:54:41,500+0530]-[ERROR]-[InventoryValidator]-[13] Exception in fetching product information - Product Not Available

Что ж, в этом журнале не так много информации, не так ли? Такой журнал не имеет большого смысла, поскольку в нем отсутствует контекстная информация об ошибке.

Можем ли мы добавить в этот журнал больше информации, чтобы сделать его более актуальным для отладки? Как насчет добавления идентификатора заказа и продукта?

log.error("Exception in processing Order #{} for Product #{} due to exception - {}", orderId, productId, ex.getResponseBodyAsString())

Будет выведен журнал в следующем формате

[2020-09-27T18:54:41,500+0530]-[ERROR]-[InventoryValidator]-[13] Exception in processing Order #182726 for Product #21 due to exception - Product Not Available

Теперь это имеет большой смысл !! Просматривая журналы, мы можем понять, что при обработке заказа № 182726 произошла ошибка, поскольку продукт № 21 был недоступен.

Как войти

Хотя приведенный выше журнал имеет смысл для нас, людей, он может быть не лучшим форматом для машин. Давайте рассмотрим пример, чтобы понять, почему.

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

Вы с радостью делаете grep для Продукта № 21 в своих журналах и с нетерпением ждете результатов. Когда поиск завершится, вы получите что-то вроде этого

[2020-09-27T18:54:41,500+0530]-[ERROR]-[InventoryValidator]-[13] Exception in processing Order #182726 for Product #21 due to exception - Product Not Available
[2020-09-27T18:53:29,500+0530]-[ERROR]-[InventoryValidator]-[13] Exception in processing Order #972526 for Product #217 due to exception - Product Not Available
[2020-09-27T18:52:34,500+0530]-[ERROR]-[InventoryValidator]-[13] Exception in processing Order #46675754 for Product #21 due to exception - Product Not Available
[2020-09-27T18:52:13,500+0530]-[ERROR]-[InventoryValidator]-[13] Exception in processing Order #332254 for Product #2109 due to exception - Product Not Available

Не совсем то, чего мы ожидали, верно? Итак, как мы можем это улучшить? На помощь приходит структурированное ведение журнала.

Структурированное ведение журнала

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

  • Разработчики могут искать в журналах и сопоставлять события, что неоценимо как во время разработки, так и для устранения производственных проблем.
  • Бизнес-группы могут анализировать эти журналы и выполнять анализ по определенным полям (например, количество уникальных продуктов в день), извлекая и суммируя эти поля.
  • Вы можете создавать информационные панели (как деловые, так и технические), анализируя журналы и выполняя агрегирование по соответствующим полям.

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

log.error("Exception in processing OrderId={} for ProductId={} due to Error={}", orderId, productId, ex.getResponseBodyAsString())

Будет выведен журнал в следующем формате

[2020-09-27T18:54:41,500+0530]-[ERROR]-[InventoryValidator]-[13] Exception in processing OrderId=182726 for ProductId=21 due to Error=Product Not Available

Теперь это сообщение журнала может быть легко проанализировано машиной с помощью знака «=» в качестве разделителя для извлечения полей OrderId, ProductId и Error. Теперь мы можем выполнить точный поиск по ProductId=21, чтобы выполнить нашу задачу.

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

Если вы используете систему управления журналами, такую ​​как Splunk, запрос Error=”Product Not Available” | stats count by ProductId теперь может дать следующий результат

+-----------+-------+
| ProductId | count |
+-----------+-------+
| 21        | 5     |
| 27        | 12    |
+-----------+-------+

Мы также могли бы использовать макет JSON для печати наших журналов в формате JSON.

{
  "timestamp":"2020-09-27T18:54:41,500+0530"
  "level":"ERROR"
  "class":"InventoryValidator"
  "line":"13"
  "OrderId":"182726"
  "ProductId":"21"
  "Error":"Product Not Available"
}

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

Заключение

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

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

Примечание

Это первая часть моей серии статей о наблюдаемости микросервисов. Я буду добавлять ссылки на следующие статьи, когда они будут опубликованы. Будьте на связи!!