Кручу, верчу логи при помощи SQL — облегчаем анализ данных

Сергей Пятько

Инженер-программист INOSTUDIO

Бывает такая ситуация, что необходимо проанализировать большой объём данных системы логирования событий на предмет аномалий или инцидентов. Просматривать такой массив данных трудно и нецелесообразно. Для этих целей можно обратиться к специализированному программному обеспечению, но нужно знать к какому. Не всегда есть время на изучение. И хорошо, если под конкретные задачи на примете есть несколько вариантов. А если их нет, тогда как быть?

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

1. SQL Server 2017 или позднее;
2. SQL Server Management Studio (SSMS);
3. Понимание синтаксиса sql-запросов (SQL — Structured Query Language) хотя бы на базовом уровне. Если с этим пунктом есть трудности, можно обратиться к официальной документации Microsoft: Учебник. Составление инструкций Transact-SQL

Проверить версию установленного MS SQL Server можно при помощи sql-запроса в той же SSMS:

			SELECT @@VERSION AS [SQL Server Version]
		

Результат выполнения запроса можно наблюдать на изображении ниже.

Или посмотреть версию SQL-сервера в Object Explorer, предварительно подключившись к нему.

Для выполнения sql-запросов использовалась SSMS версии 18.4 (более поздние версии также подойдут).

Internet Information Services и лог-файлы

В качестве эксперимента возьмём лог-файлы за пять дней с трёх серверов, на которых запущен Internet Information Services (IIS).

IIS — это веб-сервер, разработанный компанией Microsoft для своих операционных систем. Продукт полностью проприетарный и идёт в комплекте с Windows. Первая версия появилась в Windows NT и продолжает развиваться. По умолчанию IIS выключён в операционной системе.

Запустим диспетчер служб IIS на одном из серверов через меню «Пуск», написав в поисковой строке слово «IIS». Либо нажмите комбинацию клавиш Win+R, введите %SystemRoot%System32InetsrvInetmgr.exe и щёлкните «Ok».

После запуска диспетчера служб IIS (одним из двух способов) нам необходимо перейти в категорию Sites для определения значения ID. Оно понадобится нам для правильной идентификации каталога с лог-файлами интересующего нас сайта. Нам нужны логи для сайта с ID = 2.

Затем выбираем в левой секции Sites сайт по имени и затем в правой части раздела IIS нажимаем на Logging.

В группе Log Files находим расположение каталога (поле Directory), куда IIS сохраняет логи и формат сохраняемого файла (поле Format). В нашем случае лог-файлы сохраняется в W3C-формате. Подробнее с этим форматом можно познакомиться на официальном сайте Microsoft в руководстве W3C Logging. Копируем или запоминаем путь основного каталога с лог-файлами.

Чтобы просмотреть, какие поля включены для логирования, нажимаем на кнопку Select Fields. Эти данные понадобятся нам в дальнейшем для составления sql-скрипта и таблицы для хранения этих же значений. Так как мы забираем логи с 3-х машин, то отмеченные поля должны совпадать на всех машинах. Если по каким-то причинам есть расхождения, мы не сможем загрузить данные по логам в SQL ввиду их неконсистентности.

Далее переходим в директорию, куда IIS сохраняет логи. Структура папок будет такая: W3SVC[ID], где ID — значение нужного нам сайта. Забираем каталог с именем W3SVC2 или только часть содержимого этого каталога на локальную машину (логи за отдельный день с одной машины могут весить от 200 до 700 Мб). Эти действия по сохранению логов повторяем для оставшихся серверов.

Общий объём данных лог-файлов, собранных с серверов за 5 дней составил примерно 5 Гб на локальной машине.

Пишем sql-скрипты

Половина работы выполнена. Лог-файлы мы скачали себе локально на машину. Убедились, что все поля в них одинаковые по структуре. Теперь нужно их каким-то образом загрузить в базу данных SQL Server.

Запускаем SSMS и подключаемся к локальному серверу.

Создание базы данных

Для начала нам нужно создать на локальном сервере базу данных (БД). Желательно создать её на твердотельном SSD-диске, чтобы подсистема ввода-вывода не стала узким местом при импорте и выполнении запросов на большом количестве данных. Можно сделать это двумя способами:

1. написать скрипт;
2. создать БД через интерфейс SSMS.

Для первого варианта воспользуемся инструкцией CREATE DATABASE. Более подробно с ней можно ознакомиться в разделе «Создание базы данных» с использованием Transact-SQL (T-SQL) официальной документации Microsoft. Итоговый скрипт будет выглядеть так (после создания скрипта не забываем выполнить его):

			USE [master]

CREATE DATABASE [IISLogs] ON (
     NAME = [IISLogs]
    ,FILENAME = 'd:SQLDatabaseDATAIISLogs.mdf'
    ,SIZE = 8MB
    ,FILEGROWTH = 64MB
) LOG ON (
     NAME = [IISLogs_log]
    ,FILENAME = 'd:SQLDatabaseDATAIISLogs.ldf'
    ,SIZE = 8MB
    ,MAXSIZE = 1024MB
    ,FILEGROWTH = 64MB
)
		

Для второго варианта жмём правой кнопкой мыши на раздел с именем Databases и в контекстном меню выбираем пункт New Database.

В появившемся окне указываем имя БД, пути и лимиты на основную БД и её лог при необходимости.

Создание таблицы для хранения данных

Итак, у нас уже создана БД. Создадим таблицу для хранения логов. Для этого сверимся с заголовками, которые находятся в самих лог-файлах. Выберем один такой файл и откроем его. Нас интересует 4-я строка.

Копируем её и убираем значение #Fields:. Разделителем между данными служит пробел. С помощью него превращаем одну строку в набор строк и сверяемся с их количеством. В моём случае их получилось ровно 22. Соответственно, в итоговой таблице будет 22 столбца с такими же именами.

С именами столбцов определились, самое время написать скрипт создания таблицы с инструкцией CREATE TABLE. Подробную информацию о ней смотрите на сайте docs.microsoft.com. Итоговый скрипт будет выглядеть так (после создания скрипта не забываем выполнить его):

			USE [IISLogs]

DROP TABLE IF EXISTS [dbo].[Log]

CREATE TABLE [dbo].[Log] (
     [date]            DATE           NULL
    ,[time]            TIME           NULL
    ,[s-sitename]      VARCHAR (1024) NULL
    ,[s-computername]  VARCHAR (1024) NULL
    ,[s-ip]            VARCHAR (16)   NULL
    ,[cs-method]       VARCHAR (16)   NULL
    ,[cs-uri-stem]     VARCHAR (4096) NULL
    ,[cs-uri-query]    VARCHAR (5120) NULL
    ,[s-port]          VARCHAR (4)    NULL
    ,[cs-username]     VARCHAR (40)   NULL
    ,[c-ip]            VARCHAR (16)   NULL
    ,[cs-version]      VARCHAR (256)  NULL
    ,[cs(User-Agent)]  VARCHAR (5120) NULL
    ,[cs(Referer)]     VARCHAR (5120) NULL
    ,[cs-host]         VARCHAR (1024) NULL
    ,[sc-status]       INT            NULL
    ,[sc-substatus]    INT            NULL
    ,[sc-win32-status] INT            NULL
    ,[sc-bytes]        INT            NULL
    ,[cs-bytes]        INT            NULL
    ,[time-taken]      INT            NULL
    ,[X-Forwarded-For] VARCHAR(1024)  NULL
    ,INDEX [cci] CLUSTERED COLUMNSTORE
)
		

Максимальные значения текстовых полей (VARCHAR) подобраны эмпирически и их размера вполне должно хватить для импортируемых данных. Но может возникнуть ситуация, когда импорт будет падать с ошибкой. Так может произойти, когда бот или сканер генерирует в запросах «паразитную» нагрузку и значение не помещается в максимальный размер поля. Тогда можно указать для всех текстовых полей максимальное значение параметром MAX (но лучше так не делать и найти «виновника» в данных для указания конечного размера по полю).

Импорт данных

Для импорта нам понадобятся следующие инструкции T-SQL:

• xp_cmdshell
• BEGIN TRANSACTION
• COMMIT TRANSACTION
• ROLLBACK TRANSACTION
• TRY… CATCH
• OBJECT_ID
• FORMATMESSAGE
• BULK INSERT

И сам итоговый скрипт.

			USE [IISLogs]

   DECLARE @logFilePath VARCHAR(80)  = 'd:IISLoglogs'
   DECLARE @pattern   VARCHAR(8)   = '*.log'
   DECLARE @query     VARCHAR(512) = FORMATMESSAGE('master.dbo.xp_cmdshell "dir %s%s /s /b /o:d"', @logFilePath, @pattern)
          ,@tableName   VARCHAR(80)  = '[dbo].[Log]'
          ,@count     BIGINT     = 0
          ,@max       BIGINT
          ,@filename  VARCHAR(250)

BEGIN TRANSACTION
BEGIN TRY

    IF (OBJECT_ID(@tableName) IS NOT NULL) BEGIN

        CREATE TABLE #tmpDataFiles (
            [Id] BIGINT IDENTITY(1, 1) NOT NULL
           ,[Name] VARCHAR(200)
        )
        INSERT #tmpDataFiles EXEC (@query)
        DELETE #tmpDataFiles WHERE [Name] IS NULL

        SELECT * FROM #tmpDataFiles

        SET @max = (SELECT MAX([Id]) FROM #tmpDataFiles)

        WHILE @count <= @max BEGIN
            SET @count = @count + 1
            SET @filename = (SELECT [Name] FROM #tmpDataFiles WHERE [Id] = @count)
            SET @query = FORMATMESSAGE('BULK INSERT %s FROM ''%s'' WITH ( FIRSTROW = 1, FIELDTERMINATOR = '' '', ROWTERMINATOR = ''n'')', @tableName, @filename)

            IF (@filename IS NOT NULL) BEGIN
                PRINT @query
                EXEC (@query)
            END
        END
    END ELSE BEGIN
        PRINT FORMATMESSAGE('the %s table is not exists', @tableName)
    END

END TRY
BEGIN CATCH

    SELECT ERROR_NUMBER() AS ErrorNumber
          ,ERROR_SEVERITY() AS ErrorSeverity
          ,ERROR_STATE() AS ErrorState
          ,ERROR_PROCEDURE() AS ErrorProcedure
          ,ERROR_LINE() AS ErrorLine
          ,ERROR_MESSAGE() AS ErrorMessage
          ,@filename AS [FileName]
          ,@count AS [Count]
          ,@max AS [Max]

    IF @@TRANCOUNT > 0 ROLLBACK TRANSACTION;

END CATCH

IF @@TRANCOUNT > 0 COMMIT TRANSACTION

DROP TABLE IF EXISTS #tmpDataFiles
		

Примечание. В приведённом sql-скрипте по импорту данных можно обойтись без использования таких операторов, как:

• BEGIN TRANSACTION;
• COMMIT TRANSACTION;
• ROLLBACK TRANSACTION.

Запускаем скрипт и идём наливать чай, так как время выполнения импорта может занять от 2 и более минут в зависимости от объёма данных, находящихся в лог-файлах. Результат выполнения скрипта можно увидеть, если нажать на вкладку Messages.

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

			SELECT FORMAT(COUNT(*), 'N', 'ru-RU') AS [Count]
  FROM [IISLogs].[dbo].[Log]
		

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

Например, можно посмотреть, сколько было запросов, с каких IP-адресов и где сервер возвращал в таких запросах статус 404.

			SELECT [sc-status]
        ,[X-Forwarded-For]
        ,COUNT(*) AS [Count]
    FROM [IISLogs].[dbo].[Log]
   WHERE [sc-status] = 404
     AND [date] = '2022-01-17'
     AND [time] BETWEEN '00:00:00.000' AND '23:59:59.999'
GROUP BY [sc-status]
        ,[X-Forwarded-For]
  HAVING COUNT(*) > 100
ORDER BY [Count] DESC
		

Сразу виден топ IP-адресов по количеству запросов. Это либо боты, либо сканеры. Берём первый IP из списка и смотрим на его запросы. И убеждаемся, что это действительно бот/сканер.

			SELECT [cs-method]
        ,[cs-uri-stem]
        ,[cs-uri-query]
        ,[cs(User-Agent)]
        ,[sc-status]
        ,COUNT(*) AS [Count]
    FROM [IISLogs].[dbo].[Log]
   WHERE [date] = '2022-01-17'
     AND [time] BETWEEN '00:00:00.000' AND '23:59:59.999'
     AND [X-Forwarded-For] = '128.199.XXX.101'
GROUP BY [cs-method]
        ,[cs-uri-stem]
        ,[cs-uri-query]
        ,[cs(User-Agent)]
        ,[sc-status]
ORDER BY [Count] DESC
		

Вот так относительно просто можно заниматься аналитикой «небольшого» объёма данных лог-файлов. И необязательно это могут быть только логи с IIS. Загружать в БД SQL для анализа можно почти всё что угодно, было бы желание.