Введение

Опираясь на данное руководство, вы сможете понять, какую полезную информацию можно почерпнуть из логов платформы. Также в руководстве описываются принципы работы с системами логирования, которые используются в платформе. В первую очередь в платформу встроен стек Grafana (см. подробно статью Встроенные компоненты мониторинга), а также в составе дистрибутива имеется Docker образ Seq для ознакомления (в будущем его планирует убрать и функционал отправки в него логов с компонентов отключить). Мы разберём синтаксис запросов, как читать логи, на что обращать внимание в логах и пр.

Содержание

1. События платформы

Платформа регистрирует большое количество различных событий, которые могу быть нам полезны. К ним относятся события входа на платформу, просмотра дашбордов, создание\редактирование\удаление объектов в платформе (пользователи, роли, дашборды и т.п.), редактирование параметров платформы и многие другие. 
Чтобы понять, как фильтровать такие события, и была написана эта статья.

Начнём с того, что компоненты платформы имеют как минимум два уровня логирования: Standard (по умолчанию) и Full. Большинство событий, которые мы будем рассматривать в данном руководстве, пишутся на уровне Full. Как сменить уровень логирования можно узнать тут - Настройка логирования в docker контейнерах. В примерах будет написано, на каком уровне логирования компонента пишется конкретное событие.

2. Система логирования Seq. Синтаксис запросов.

Данная система не установлена по умолчанию. Для установки следует воспользоваться инструкцией - Установка системы логирования.

В данной системе мы можем использовать различные подходы в формировании запроса для фильтрации. Ниже будут рассмотрены основные и наиболее удобные, которые помогут решать наши задачи. Почитать всю документацию по Seq можно по ссылке - https://docs.datalust.co/docs/query-syntax . Там расписано всё до мелочей. 

В Seq есть два способа исследования логов:

• Поисковые выражения – для фильтрации событий;

• SQL-like запросы – для анализа и дашбординга.

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

Фильтрация по названию события

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

Чтобы найти такие записи, в строке запроса мы пишем это наименование:

"Успешный вход в платформу"

Можно писать лишь часть имени, например:

"Успешный вход"

Фильтрация по параметру события

У каждого события есть параметры. На картинке выше видно, что у события "Успешный вход в платформу" есть параметры: ActionID, ActionName, Component и т.д.
Например, мы хотим найти все события входа в платформу пользователя admin, запрос будет выглядеть так:

"Успешный вход" and Username = "admin"

Мы использовали логический оператор И и добавили к фильтру параметр Username, который должен быть равен admin.

Логические операторы

В запросах мы можем использовать and, or и not. Например, как в запросе выше. Давайте слегка усложним запрос:

"Успешный вход" and (Username = "admin" or Username = "testAdmin")

Мы отфильтруем все события входа в платформу пользователей admin и testAdmin.

Объекты и массивы

В качестве параметра события может выступать объект, например:

Request = {user: {GivenName: "", FamilyName: "testUser", MiddleName: "", Email: "", UserName: "testUser", IsInfrastructure: false, Roles: ["Все авторизованные пользователи"], IsBlocked: false, Password: "*"}, changePass: true}

В данном случае у нас объект объектов. Например, мы хотим отфильтровать события, в параметре Request которых changePass равен true. Это говорит нам о том, что была произведена смена пароля. Мы напишем следующий запрос:

Request.changePass = true

Синтаксис похож на JS. Мы обращаемся к ключу changePass, который находится в объекте Request. Обращайте внимание на тип данных, в данном случае у нас логический тип и писать следует без кавычек. 

Если в качестве параметра у нас массив, например:

Products = ["pen", "pineapple", "apple"]

То мы обращаемся к элементам массива по индексу, а если индекс не известен, то используем знак ?:

Products[0] = "pen"
Products[?] = "apple"

Регулярные выражения

Для фильтрации событий с помощью регулярного выражения, используем /выражение/. Например:

/У.*д/

С помощью данного выражения найдём события "Успешный вход", т.к. . - это любой символ, а * - это квантификатор, означающий, что любых символов может быть 0 или больше.

SQL-like запросы

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

select count(*) from stream where @Message like 'Успешный вход%' and Username = 'admin'

Результат будет выглядеть вот так:

Из запроса видно, что мы считаем события из потока, где сообщения выглядят как "Успешный вход ..." и Username равен admin.

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

 Пример просмотра активности пользователей

select count(*) from stream where UserFullName <> ' Администратор' and UserFullName <> ' Сервер дэшбордов' and UserFullName <> ' Preview генератор' group by time(1m)

Суммарное количество запросов на сервер по оси Y.

2. Система логирования Grafana. Синтаксис запросов

Данная система установлена по умолчанию. Найти её можно в веб администрировании платформы, вкладка Основные - Мониторинг - События.

У этой системы немного другой подход к представлению и фильтрации событий. В строке ввода запроса в самом начале в фигурных скобках указывается поток либо компонент, события которого следует фильтровать. Также не стоит забывать о том, что по умолчанию в Графане установлен небольшой период времени (1ч), за который показываются события; при необходимости измените период.
В конце записи каждого события присутствует ссылка "Show context", нажав на которую мы увидим события, которые стоят до и после найденного события.

Давайте посмотрим, каким образом мы можем фильтровать события в Grafana.

Фильтрация по строке

Все события в Grafana представлены в виде строки. Чтобы фильтровать по строке мы используем следующую конструкцию: |="строка".
Разберём случай с поиском событий входа в платформу. Мы знаем, что в событии присутствует строка "Успешный вход в платформу", поэтому мы можем написать вот так:

{stream="stdout"} |="Успешный вход"

Мы получим вот такие записи:

Пойдём дальше и найдём все записи входа в платформу пользователя admin:

{stream="stdout"} |="Успешный вход" |="admin"

Мы фильтруем записи по строке "Успешный вход" и далее уже их фильтруем по строке "admin". Так как у нас нет параметра Username как в Seq, информацию о пользователе мы берём из текста самого события.

Если нам необходимо, наоборот, исключить строку из поиска, то мы используем следующую конструкцию: !="строка" - она работает как НЕ.

{component="smart-forms"}!="Error unprotecting the session cookie"

Фильтрация по регулярному выражению

Чтобы фильтровать события по регулярному выражению в Grafana, мы используем: |~`выражение`. Если написать с использованием двойных кавычек: |~"выражение" - то придётся использовать экранирование для \, т.е. писать не \w+, а \\w+. Также если мы используем двойные кавычки "", то искомый текст подсвечивается в записях, но ровно до того момента пока мы не начнём использовать конструкции вида: \w, \d, \s и так далее, либо писать запрос в обратных кавычках ``. В Grafana используется синтаксис RE2, более подробно о нём написано тут - https://github.com/google/re2/wiki/Syntax .

Давайте для примера найдём события смены пароля пользователей:

{stream="stdout"} |~"Completed operation PUT: /user|changePass: true"

В данном выражении мы использовали оператор ИЛИ - |. Тем самым мы найдём все записи содержащие "Completed operation PUT: /user" или "changePass: true". На данный момент события в Grafana представлены множеством записей. Т.е. событие о смене пароля будет в нескольких записях и фильтровать не очень удобно, но возможно.

4. Примеры фильтрации на реальных кейсах

Начну с того, что события создания, редактирования и удаления сущностей можно найти по следующим строкам:
Создание - Completed operation POST
Изменение - Completed operation PUT
Удаление - Completed operation DELETE

После этого следует двоеточие и название сущности, например : /user.

Практически все события, которые рассмотрены ниже, генерируются на уровне логирования Full для таких компонентов, как: Identity server, Dashboard service, Dashboard viewer.

Список запросов для Seq

Вход в платформу

"Успешный вход"
Запрос обычно используется с параметром Username = "имяПользователя", дабы узнать, когда на платформу заходил конкретный пользователь.

Создание пользователя

/Completed operation POST: \/\buser\b/
Если необходимо узнать, кто создал пользователя testAdmin, пишем так:
/Completed operation POST: \/\buser\b/ and Request.UserName = "testAdmin"
Далее в параметрах события смотрим UserFullName.

Изменение пароля пользователя

RequestPath = "/api/user" && Request.changePass = true && Request.user.UserName = "testUser"
Так мы узнаем, кто сменил пароль пользователю testUser.

Удаление пользователя

/Completed operation DELETE: \/\buser\b/ && Request.UserName = "testUser2"

Создание роли

"Completed operation POST: /role"

Удаление роли

"Completed operation DELETE: /role"

Редактирование прав доступа на папки

"Completed operation PUT: /highLevelFolders"

Редактирование прав доступа на дашборды

"Completed operation PUT: /dashboard"

Изменение "Общих настроек"

"Completed operation PUT: /generalSettings"

Общее количество просмотров дашборда

select count(*) from stream where @Message like 'Done Handling GetDashboardAggregateRoot%' and Response.Result.Name = 'TEST'
Имя дашборда в данном примере "TEST". Нужно учитывать, что считаются просмотры, как с браузера, так и с дизайнера. Также нужно учесть, что за просмотр считается генерация превью дашборда, такое событие можно исключить по имени пользователя: UserFullName not like '%Preview генератор'.

Уникальный список всех просмотренных дашбордов

select distinct(Response.Result.Name) from stream where @Message like 'Done Handling GetDashboardAggregateRoot%'
Также можно подсчитать уникальное количество дашбордов, для этого стоит distinct заключить в count().

Уникальный список всех просмотренных дашбордов с Python виджетами

select distinct(Response.Result.Name) from stream where @Message like 'Done Handling GetDashboardAggregateRoot%' and Response.Result.Sheets[?].Widgets[?].DataSettings.DatasourceType = 'Python'

Список запросов для Grafana (Loki)

Вход в платформу

{stream="stdout"} |~"Успешный вход"
Также как и в случае с Seq, можно добавить имя пользователя - |~"Username: ..имяПользователя".

Создание пользователя

{stream="stdout"} !="Completed operation POST: /users" |~"Completed operation POST|UserFullName" |~"/user|Администратор"
После фильтрации можно использовать "Show context" в конце строки для изучения записей находящихся выше или ниже.

Удаление пользователя

"Completed operation DELETE: /user"

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

5. Видео - Системы логирования в платформе Visiology

Loki LogQL: https://www.youtube.com/embed/7h1-YMFjldI