Гайд по логам для тестировщиков

Почти четыре года я познаю дивный мир тестирования в департаменте корпоративных систем ЛАНИТ. Последние полтора ― на финтехпроектах, поэтому работа с логами стала частью моего рабочего процесса. В этом гайде я познакомлю вас с ключевыми моментами, которые помогут понять логи лучше и применять инструменты логирования эффективнее.

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

Что такое лог и логирование

В любой непонятной ситуации смотрите логи!

Кратко напомню, что такое логи и логирование. Лог (log) — это файл с записями о событиях, происходящих в системе. Это как чёрный ящик в самолете, только для программ: в случае чего в лог‑файлах фиксируется информация, помогающая отслеживать поведение процессов в работе системы. Чаще рассматривают логи сервера.

Логирование — процесс формирования логов, то есть фиксация и структурирование информации о работе системы в отдельные лог‑файлы, чтобы можно быстро получить к ним доступ.

Логи записывают разную информацию: от скорости работы приложения (время отклика) до данных об ошибках, исключениях и проблемах.

Логи полезны, когда…

На самом деле все зависит от цели проводимого тестирования, уровней доступа на стендах и возможностей систем логирования.

Настроенные логи и доступ к ним для тестировщика ускорят разбор инцидентов на продакшене, так как описание проблемы часто бывает неполным или нечётким при воспроизведении дефекта.

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

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

А в каком случае, собственно, запрашивать логи или идти их искать?

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

При повторном нажатии, но уже с открытым DevTools, вы видите, что запрос на получение курса валют падает с 422-й ошибкой. В DevTools деталей по ошибке нет. В таком случае идём в логи. Там можем узнать, что запрос упал с 422-й ошибкой, так как бэкэнд обрабатывает в это поле только значения меньше 100, а сторонний сервис присылает нам ответ, например, 120.

Какую информацию может смотреть тестировщик в логах?

• Запросы и ответы, коды состояния,

• выполнение операций, последовательность событий,

• исключения (механизмы, обрабатывающие нетипичные ситуации и не прекращающие работу),

• трассировку стека (список методов, которые были вызваны до момента, когда в приложении произошло исключение),

• сообщения об ошибках или недостаточных данных,

• выполнение определенных операций, использование ресурсов (например, процессора, памяти).

Какие типы логов существуют

Чтобы понимать, на каком этапе произошла ошибка и к какому логу обратиться, логи делятся на следующие типы.

1. Системные

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

2. Логи приложения

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

3. Логи сервера

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

4. Логи базы данных

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

Дополнительно для удобства обработки логи делятся на подтипы:

• системные, связанные с системными событиями,

• серверные, отвечающие за процесс обращения к серверу,

• почтовые, работающие с отправлениями,

• логи баз данных, которые отражают процессы обращения к базам данных,

• авторизационные и аутентификационные, которые отвечают за процесс входа‑выхода из системы, восстановление доступа и т. д.

Плюсы и минусы системного ПО с возможностью логирования и визуализации логов

Итак, мы рассмотрели, что такое логи, логирование и типы логов. Здесь я бы хотел подсветить три самых распространенных инструмента на проектах среди наших сотрудников, которые предоставляют возможность поработать с логами и дополнительной информацией об ошибках и событиях. Они часто встречаются в перебрендированном виде (большинство этих продуктов open source), но по сути это те же инструменты, только переработанные и локализованные под требования продукта.

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

1. Openshift — инструмент для развертывания, управления и масштабирования контейнерных* приложений

Для чего использовать?

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

Плюсы:

• управление контейнерами через веб-интерфейс,

• мониторинг и управление ресурсами,

• удобное разбиение логов и информации по сервисам,

• возможность точечного перезапуска сервисов.

Минусы:

• требует времени для изучения и настройки.

Справка по Openshift

2. Kafka — инструмент для обработки и передачи потоковых данных

Для чего использовать?

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

Плюсы:

• сообщения хранятся в очередях продолжительное время,

• встроенная функциональность для форматирования ответов под тип сообщения (Json, xml и т. д.).

Минусы:

• сложно отправлять сообщения напрямую (нужны инструменты).

Справка по Kafka — тут и тут

3. Kibana — инструмент визуализации и анализа данных из Elasticsearch

Elasticsearch — открытая распределённая система управления данными и поиска по ним. Она позволяет индексировать, хранить, находить и анализировать большие объёмы информации в реальном времени. В Elasticsearch хранятся логи, которые визуализирует Kibana.

Для чего использовать?

В удобном виде отлавливать логи с гибкой фильтрацией. Например, почти у всех запросов есть id трассировки. Он же traceid — уникальный идентификатор запроса в системе трейсинга, который позволяет в деталях проследить за историей выполнения запроса. Его можно найти на главной странице запроса в DevTools. При поиске по этому id в Kibana будут отображаться только логи, связанные с этим событием. В Kibana также удобно проводить фильтрацию логов по отдельным сервисам.

Плюсы:

• интуитивно понятный интерфейс для создания дашбордов и отчётов,

• большие возможности фильтрации и агрегации данных,

• интеграция с Elasticsearch для эффективного анализа больших объёмов логов,

• удобно разбивает логи на различные части, отсекая лишнее.

Минусы:

• сложности с настройкой и оптимизацией запросов при больших объемах данных.

Демопесочницы — ссылка

Справка — тут

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

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

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

Kibana — довольно сбалансирована по удобству работы с логированием относительно других инструментов. Её легко освоить, а если углубиться, то она даст много возможностей. Грамотно настроенная Kibana позволит быстро находить нужную информацию. Например, удобно отлавливать события по их traceid. Большое количество возможностей визуализации и фильтров вкупе с интуитивно понятным интерфейсом здесь как раз в тему.

Из дополнительных инструментов: с классическим логом, как в Openshift, довольно удобно работать в Notepad++. Он спокойно справляется даже с супердлинными записями, имеет множество хоткеев для быстрого редактирования и адекватный поиск. Сообщения из Kafka также просматриваются в Notepad++. Есть плагины, которые форматируют сообщения (например, json или xml) в читаемый вид.

Стоит, отметить, что Notepad++ доступен только для Windows. Для тех, кто пользуется Linux — Vim или Emacs, альтернативы под MacOS — VSCode, Zed, SublimeText и др.

С чего начать перед работой с логами

С понимания, насколько важная информация будет записываться в лог‑файлы. Это определяют уровни логирования. В большинстве инструментов для работы с логами принято использовать следующие стандартные уровни.

• TRACE — самый низкий уровень детализации. Используется для записи самой подробной информации о выполнении программы (значения переменных, шаги выполнения алгоритмов и т. д.). Обычно не рекомендуется использовать этот уровень в проде из‑за большого объема записываемых данных.

• DEBUG — используется для записи отладочной информации, которая помогает выявлять и исправлять ошибки в программном коде. Этот уровень полезен во время разработки и тестирования приложения.

• INFO — используется для записи основной информации о работе программы (запуск и остановка сервисов, начало и завершение задач и т. д.). Этот уровень часто используется для мониторинга работы приложения в проде.

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

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

• FATAL — пожалуй, самый высокий уровень логирования. Используется для записи критических ошибок, которые привели к неработоспособности приложения или серьезным последствиям. Этот уровень логирования сигнализирует о необходимости перезапуска приложения или системы.

Что важно учитывать при выборе уровня логирования

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

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

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

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

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

Как читать логи и другие ключевые моменты организации логирования, которые должен знать тестировщик

Рассмотрим два примера распространенных образцов логов. С ними можно столкнуться в OpenShift или Kibana. На их основе я постараюсь объяснить, что находится в логах и что означает каждый фрагмент. 

Пример 1 

Возьмём небольшой список событий:

2023-02-15 10:23:45 [INFO] GET /api/users/123456
2023-02-15 10:24:02 [ERROR] POST /api/login
2023-02-15 10:25:12 [WARN] GET /api/products?category=electronics

Разберем, что под этим всем скрывается:

2023-02-15 10:23:45: это дата и время события. В данном случае событие произошло 15 февраля 2023 года в 10 часов 23 минуты 45 секунд.

[INFO], [ERROR], [WARN]: это уровни логирования или типы события:

• [INFO]: информационное сообщение. В данном случае это успешный запрос на получение данных о пользователе.

• [ERROR]: сообщение об ошибке. В данном случае это ошибка при попытке входа пользователя.

• [WARN]: предупреждение. В данном случае это предупреждение о получении данных о продуктах с категорией electronics.

GET /api/users/123456, POST /api/login, GET /api/products?category=electronics: это HTTP-методы и URL запросов.

GET /api/users/123456: запрос на получение данных о пользователе с идентификатором 123456 POST /api/login: запрос на вход пользователя.

GET /api/products?category=electronics: запрос на получение списка продуктов с категорией electronics.

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

Пример 2

Возьмем список событий побольше:

2023-02-15T10:23:45.123456Z [DEBUG] [Thread-1] com.example.Application: Starting application initialization process
2023-02-15T10:24:02.987654Z [ERROR] [Thread-5] com.example.Controller: Error processing request for /api/users/123456
java.lang.NullPointerException: User ID is null
at com.example.Service.getUserById(Service.java:78)
at com.example.Controller.getUserDetails(Controller.java:56)
at com.example.Controller.handleRequest(Controller.java:32)
at sun.reflect.GeneratedMethodAccessor42.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
. . .
2023-02-15T10:25:12.345678Z [INFO] [Thread-8] com.example.Application: Application initialization process completed successfully

Разберем его. Здесь лог содержит информацию:

2023-02-15T10:23:45.123456Z: дата и время события в формате ISO 8601 с миллисекундами и временной зоной.

[DEBUG], [ERROR], [INFO]: уровни логирования.

[Thread-1], [Thread-5], [Thread-8]: имя потока, в котором произошло событие. Поток – это номер пути, по которому идут процессы. Они нужны для равномерного распределения нагрузки. Знание потока пригодится, чтобы, например, отловить сообщение в нужном потоке топика Kafka.

com.example.Application, com.example.Controller, com.example.Service: полное имя класса** или компонента***, который вызвал лог.

**Класс – это шаблон кода, по которому создаётся какой-то объект.

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

Starting application initialization process, Error processing request for /api/users/123456, Application initialization process completed successfully: сообщение о событии или описании ошибки.

java.lang.NullPointerException: User ID is null: стек вызова и описание исключения. Затем сам стек вызова Java с указанием методов и классов, которые привели к возникновению ошибки.

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

• дату и время события с миллисекундами,

• уровень логирования,

• имя потока,

• класс или компонент,

• сообщение о событии или ошибке, стек вызова и описание исключения.

Ключевые моменты организации логирования, которые должен знать тестировщик

Фича 1 — ротация файлов

Представим, что логирование данных системы налажено. Например, мы прописали в приложении уровни: debug, info, warning, error. Выбрали в качестве механизма записи обычные текстовые файлы, и логи благополучно собираются в отдельном месте. Теперь стоит разобраться с ротацией логов.

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

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

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

Фича 2 — фильтрация

Важно уметь фильтровать тот поток информации, который несут в себе логи. Базовые атрибуты, по которым можно отфильтровать лог.

1. Cервис, к которому, скорее всего, относится ошибка.

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

2. TraceId либо другой идентификатор события (если это есть).

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

3. Даты — не идеальный, но рабочий фильтр.

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

4. Иногда можно найти нужную информацию в логе, введя в поиск запрос, который отправлялся.

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

Как настроить Kafkatool, Kibana, Openshift для эффективного анализа логов и диагностики ошибок

Kafkatool

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

В свойствах топика поменяйте значения Key на String. Это делается для отображения значения сообщения в виде читаемого текста, а не байтового массива.

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

Kibana

На скриншоте ниже ― пример интерфейса мониторинга сервисов. Путь к нему варьируется в зависимости от проекта, но выглядит он одинаково. Полезно знать, как его найти, так как иногда какие-либо ошибки могут быть вызваны недоступностью сервиса. В шкале Health отображается статус сервиса. Дополнительные метрики справа показывают задержку и другую информацию. Опять же, всё меняется от проекта.

На этом скриншоте пример типичного интерфейса просмотра логов в Kibana. Строка поиска, которую мы видим, — как раз то чудо, которое поможет находить нужную информацию. Интеграция Elasticsearch позволяет гибко фильтровать информацию, комбинируя различные запросы. Например, можно запросить фильтр по id события и добавить фильтр по определенному сервису, чтобы отсечь лишнее. Elasticsearch ― сложный и интересный инструмент. В интернете огромное количество достойных гайдов по его базе.

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

Openshift

И раз мы посмотрели остальные инструменты, то уделим немного внимания Openshift. Как мы упоминали в разделе «Плюсы и минусы системного ПО…», тут в плане логов мы получаем детальные логи в чистом виде. Минимум фильтров, максимум текста. Плюс возможность выгрузить полный лог в формате txt за определенный промежуток времени. А разгребать его потом удобнее в Notepad ++.

Напоследок скажу про поды. Под в OpenShift — это один или несколько контейнеров, развёрнутых вместе на одном хосте. Вероятнее, все, что мы будем с ними делать ― это перезагружать их. Иногда это может помочь, если, например, сообщения перестали доходить в топик Kafka или застревать на каком‑то этапе. Коллеги‑разработчики на одном проекте подсказали лучший способ быстро перезагрузить под — удалить его. Он пересоздастся и перезапустится автоматически.

Заключение

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

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

3. Openshift позволит видеть сухие логи, наиболее детальные. Kafka иногда возвращают ошибку или отсутствие атрибутов. Kibana — оптимальный инструмент логирования среди первых двух: в нём удобно отлавливать события по traceid.

4. На основе того, насколько важная информация будет записываться в лог‑файлы, есть уровни логирования, при выборе которых важно опираться на уровень детализации и контекст события (время, место, вызвавший код и т. д.).

5. Кроме чтения логов, полезна такая функция, как ротация файлов и фильтрация.

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

Статьи, которые использовались в гайде, и которые можно изучить:

• О чём могут рассказать логи: важный инструмент в работе тестировщика / Хабр

• Уровни логирования: как правильно использовать логи

• Типичные ошибки при логгировании

• Что такое логирование | Hexlet Guides

• Как читать логи сервера и что это такое?

• Логирование: понятие, механизмы и уровни

• Уровни логирования