Стриминг и анализ логов Java приложений в MS Azure с использованием Log4j и Stream Analytics

В этой статье я покажу несколько работающих решений задачи передачи и анализа логов из Java приложений в MS Azure. Мы рассмотрим решения как для windows, так и для linux виртуальных машин, находящихся как в облаке, так и on-premise. В качестве подсистемы логирования для Java будем использовать log4j2.

Для анализа логов будем использовать Azure Stream Analytics.

Чтобы понять о чём вообще идёт речь в статье — желательно обладать базовыми знаниями по log4j2 и некоторым ресурсам Azure, а именно stream analytics, event hub, blob storage.
Если у вас есть желание их (знания) освежить — вот ссылки
Apache Log4j 2
Azure Stream Analytics Documentation
Azure Event Hubs
Azure Storage

Почему java?

Возможно кому-то покажется странным сама идея хостинга java приложений в Azure VM, но вот по данным из отчета по анализу рынка IaaS 20011-2026 в Германии от Colorbridge Gmbh, Azure IaaS используют лишь чуть меньше, чем AWS. Поэтому, если оставить предрассудки, такая постановка вопроса окажется вполне разумной, а кому-то — даже злободневной.

Хотя Azure поддерживает Java давно, особенно на уровне PaaS, предоставляя SDK для Java, хостинг Java приложений в Web App а также популярное в java и opensource мире ПО по схеме SaaS. Но вот на уровне IaaS (в общем-то абстрагированном от самого ПО), специфика работы с Java не сильно освещена. А она есть, как минимум в области логирования. Попытаемся это исправить.

Почему log4j?

Для java есть несколько подсистем для логирования. Мы будем использовать именно log4j потому что

• Он очень популярный
• Его возможностей по конфигурированию достаточно для интеграции с теми ресурсами Azure, которые нам будут необходимы
• Всё конфигурирование можно осуществить через внешний конфигурационный файл
• Конфигурационный файл с новыми настройками можно указать и для уже собранного приложения (-Dlog4j.configurationFile=log4j2.xml), таким образом все сценарии в статье могут быть реализованы вообще без изменения кода приложения.

На чём я тестировал

В качестве тествого приложения я брал самый обычный springboot starter app с модулем spring-boot-starter-log4j2 но последней версии 2.0.0.M5, т.к. для одного из сценариев нужна будет последняя версия log4j.

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
    xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>

    <groupId>com.example</groupId>
    <artifactId>log4j2-demo</artifactId>
    <version>0.0.1-SNAPSHOT</version>
    <packaging>jar</packaging>

    <name>log4j2-demo</name>
    <description>Demo project for Spring Boot</description>

    <parent>
        <groupId>org.springframework.boot</groupId>
        <artifactId>spring-boot-starter-parent</artifactId>
        <version>2.0.0.M5</version>
        <relativePath/>
    </parent>

    <properties>
        <project.build.sourceEncoding>UTF-8</project.build.sourceEncoding>
        <project.reporting.outputEncoding>UTF-8</project.reporting.outputEncoding>
        <java.version>1.8</java.version>
    </properties>

    <repositories>
        <repository>
            <id>sboot</id>
            <name>your custom repo</name>
             <url>https://repo.spring.io/libs-milestone</url>
            <snapshots>
                <enabled>false</enabled>
            </snapshots>
        </repository>
    </repositories>

    <dependencies>
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-web</artifactId>
            <version>2.0.0.M5</version>
        </dependency>

        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-test</artifactId>
            <scope>test</scope>
            <version>2.0.0.M5</version>
        </dependency>
        <!-- Exclude Spring Boot's Default Logging -->
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter</artifactId>
            <exclusions>
                <exclusion>
                    <groupId>org.springframework.boot</groupId>
                    <artifactId>spring-boot-starter-logging</artifactId>
                </exclusion>
            </exclusions>
        </dependency>

        <!-- Add Log4j2 Dependency -->
        <dependency>
            <groupId>org.springframework.boot</groupId>
            <artifactId>spring-boot-starter-log4j2</artifactId>
            <version>2.0.0.M5</version>
        </dependency>
    </dependencies>

    <pluginRepositories>
        <pluginRepository>
            <id>sbootplug</id>
            <url>https://repo.spring.io/libs-milestone</url>
            <snapshots>
                <enabled>false</enabled>
            </snapshots>
        </pluginRepository>
    </pluginRepositories>

    <build>
        <plugins>
            <plugin>
                <groupId>org.springframework.boot</groupId>
                <artifactId>spring-boot-maven-plugin</artifactId>
                <version>2.0.0.M5</version>
            </plugin>
        </plugins>
    </build>
</project>

Для тестирования возможности добавить функционал по стримингу логов для уже готового приложения я ставил эксперименты над java minecraft сервером :)

Что дальше?

А дальше будет несколько сценариев с указанием способа их реализации и присущими им ограничениям.

Смысл сценариев — организация пайплайна по

• сбору логов от java приложения
• передаче их в какое-нибудь хранилище в Azure (мы будем использовать или Blob Storage или EventHub)
• передаче их в Stream Analytics и первичный анализ (в основном я буду показывать как добраться из Stream Analytics до данных, переданных в log4j)
  а вот шаг потребления данных (создания всяких дашбордов и прочее) — не будет освещён в данной статье.

Сценарий 1, универсальный

Особенности: Windows или Linux OS, VM в Azure или On-premise
Ограничения: нужна <определённая> версия log4j2

Алгоритм работы:

• Логи с помощью HTTP appender'а пушатся напрямую в Azure в EventHub
• EventHub мониторит джоба Stream Analytics и при появлении сообщений начинает их разбирать и анализировать в соответствии с заданным запросом

Детали реализации:

Настройка Log4j
В конфиге log4j2 должен быть определён HTTP appender

<Http name="Http" url='https://<event hubs namespace>.servicebus.windows.net/<event hub>/messages?timeout=60&amp;api-version=2014-01'>
    <Property name="Authorization" value="SharedAccessSignature sr=xxxsig=yyyse=zzzskn=<event hub poicy>" />
    <Property name="Content-Type" value="application/atom+xml;type=entry;charset=utf-8" />
    <Property name="Host" value="<event hubs namespace>.servicebus.windows.net" />
    <JsonLayout properties="true"/>
</Http>

Чуть подробнее про Authorization хедер.
Для того, чтобы работать с REST API EventHub требуется авторизация по т.н. SaS токену. Это по сути, хеш урла ресурса и времени жизни токена.

Для формирования sas токена кроме event hub namespace и event hub также потребуется знать имя и ключ policy event hub'а с правами на отсылку сообщений. Вся информация есть на portal.azure.com.

Майкрософт предоставляет примеры кода для генерации Authorization хедера на различных языках, в т.ч. на Java.

Я же пользуюсь вот этим html снипетом, который нашёл в интернетах и слегка доработал — он генерирует Authorization хедер для EventHub с временем жизни равным году.

Настройка Stream Analytics
В Stream Analytics джобе настраивается input с EventHub с параметрами
Event serialization format = JSON, Encoding = UTF-8, Event compression type = None
При этом доступ к данным, которые пушит http appender log4j выполняется просто, непосредственно через select * from (и так будет не всегда)

Чтобы хоть чуть-чуть показать мощь Stream Analytics посмотрите пожалуйста на вот такой запрос

WITH errors as (
    SELECT
        *
    FROM
        javahub
    WHERE level='FATAL' OR level='ERROR'
),
activity as (
    SELECT
       System.TimeStamp AS WindowEnd, level, COUNT(*)
    FROM
        javahub
    GROUP BY TumblingWindow( second , 10 ), level
)

select * into pbierrors from errors;
select * into pbiactivity from activity;

Этим запросом мы

• Пересылаем в pbierrors оутпут все сообщения лога с уровнем FATAL или ERROR
• Каждые 10 секунд пересылаем в pbiactivity оутпут количество сообщений, поступивших за эти 10 секунд, сгруппированных по уровню лога

Пара кликов мышкой в power bi и мы можем мониторить не только ошибки приложения, но и следить за общей активностью.

Сценарий 2, только Windows, бюджетный

Особенности: не нужен EventHub. Меньший объём трафика (логи архивируются перед передачей), не надо заморачиваться с SaS токенами.
Ограничения: VM только в Azure. Логи поступают с небольшой задержкой.

Алгоритм работы

• Логи с помощью RollingRandomAccessFile appender'а пишутся в файл
• По достижении определённых условий (триггеры log4j) логи архивируются в отдельную папку
• Папку мониторит Azure Monitoring & Diagnostics Extension для VM и при появлении нового файла с архивом перекладывает его в Blob storage в Azure
• Blob storage мониторит джоба Stream Analytics и при появлении нового файла с архивом начинает его разбирать и анализировать в соответствии с заданным запросом

Детали реализации

Настройка Log4j
Обязательно надо обратить внимание, что

• Архивирование должно производится НЕ в ту папку, в которую пишутся текущие логи
• Каждый файл должен иметь хедер — список имён полей
• Если есть желание в папке, где архивируются логи, огранизовать иерархию директорий — в качестве имён директорий можно использовать (из динамики) только дату (yyyy-MM-dd) (разделители могут быть произвольными) иили час (HH)
  Пример определения "правильного" appender'а log4j

  <RollingRandomAccessFile name='File' fileName="latest.log" filePattern="logs%d{yyyy-MM-dd}%d{HH}%d{HH-mm-ss}-%i.log.gz">
          <PatternLayout pattern='%d{yyyy-MM-dd HH:mm:ss};%level;%msg%n'>
              <header>TS;LEVEL;MESSAGE%n</header>
          </PatternLayout>
          <Policies>
              <CronTriggeringPolicy schedule='10 * * * * ?' evaluateOnStartup='true'/>
              <SizeBasedTriggeringPolicy size='10 MB'/>
          </Policies>
          <DefaultRolloverStrategy max='100'/>
      </RollingRandomAccessFile>

Настройка Azure Monitoring & Diagnostics Extension для VM

• сформировать два конфига (примеры ниже)
• с помощью Azure CLI 2 выполнить

az vm extension set --name IaaSDiagnostics 
                    --publisher "Microsoft.Azure.Diagnostics" 
                    --resource-group <group name> 
                    --vm-name <vm name> 
                    --protected-settings "privateSettings.json" 
                    --settings "publicSettings.json" 
                    --version "1.11.1.0"

{
    "WadCfg": {
        "DiagnosticMonitorConfiguration": {
            "overallQuotaInMB": 10000,
            "DiagnosticInfrastructureLogs": {
                "scheduledTransferLogLevelFilter": "Error"
            },
            "Directories": {
                "scheduledTransferPeriod": "PT1M",
                "DataSources": [
                    {
                        "containerName": "<blob container name in your storage account>",
                        "Absolute": {
                            "path": "C:\<folder>\<to monitor>",
                            "expandEnvironment": false
                        }
                    }
                ]
            }
        }
    },
    "StorageAccount": "<your storage account name>",
    "StorageType": "Table"
}

{
    "storageAccountName": "<your storage account name>",
    "storageAccountKey": "<storage account access key (use portal to obtain it)>"
}

Настройка Stream Analytics
В качестве input используется Blob storage с параметрами:
PathPattern — путь до файлов с архивированными логами в Blob storage. Если вы делали иерархию директорий (как в примере выше) — то тут она также должна быть учтена.

Пример: WAD/be7f1c92-2841-4ea1-b9d8-ec83c211b8ea/IaaS/_minesrv/{date}/{time}/
DateFormat должен быть задан в соответствии с форматом паттерна %d в log4j
Event serialization format = CSV, Delimeter = semicolon, Encoding= UTF-8, Event compression type = GZIP

Доступ к данным в запросах Steam Analytics также непосредственный.
select * from вернёт таблицу с полями TS, LEVEL, MESSAGE (в соответствии с хедером, определённым в log4j)

WITH 
SessionInfo AS (  
    SELECT
        TS, 'START' as EVENT, SUBSTRING(MESSAGE, 0, REGEXMATCH(MESSAGE, '[ ]*joined the game')) as PLAYER
    FROM
        logslob
    TIMESTAMP BY TS
    WHERE REGEXMATCH(MESSAGE, 'joined the game') > 0
UNION
    SELECT
        TS, 'END' as EVENT, SUBSTRING(MESSAGE, 0, REGEXMATCH(MESSAGE, '[ ]*left the game')) as PLAYER
    FROM
        logslob
    TIMESTAMP BY TS
    WHERE REGEXMATCH(MESSAGE, 'left the game') > 0
),
RawLogs AS (
    SELECT
        TS, LEVEL, MESSAGE
    FROM
        logslob
    TIMESTAMP BY TS
)

SELECT * INTO sbq from SessionInfo;
SELECT * INTO pbi from RawLogs;

Тут мы пересылаем в оутпут RawLogs все логи, а вот в SessionInfo отдельно записи о старте и остановке сессии с указанием имени игрока — для последующих уведомлений

Сценарий 3, только Linux

Особенности: минимальная настройка Log4j (и минимальные требования к версии log4j) — просто запись в файл. Обрабатываются все новые записи в файле (без задержки)
Ограничения: VM только в Azure, запись в файл только в json, более сложный доступ к данным из stream analytics job

Алгоритм работы:

• Логи с помощью File appender'а пишутся в файл
• Файл мониторит Azure Linux Diagnostics Extension для VM и при появлении новых записей в файле пушит их в EventHub
• EventHub мониторит джоба Stream Analytics и при появлении сообщений начинает их разбирать и анализировать в соответствии с заданным запросом

Детали реализации

Настройка Log4j
Логи должны писаться в формате json и обязательно — каждый объект на одну строчку файла с логами
К счастью, с помощью log4j это можно настроить просто

<File name="FileLog" fileName="app.log">  
    <JsonLayout properties="true" compact="true" eventEol="true"/>
</File>

Настройка Azure Linux Diagnostics Extension для VM

• сформировать два конфига (примеры ниже)
• с помощью Azure CLI 2 выполнить

az vm extension set --name LinuxDiagnostic 
                    --publisher "Microsoft.Azure.Diagnostics" 
                    --resource-group <group name>
                    --vm-name <vm name>
                    --protected-settings "linux_privateSettings.json" 
                    --settings "linux_publicSettings.json" 
                    --version "3.0.109"

• в конфигах мы прописываем storage account, хотя он не используется для передачи логов. Он нужен только для диагностических записей самого Linux Diagnostics Extension
• в конфигах мы прописываем sas токен для sotage account (а не просто ключ, как в случае с Diagnostics Extension для Windows), к счатью сгенерировать его можно через портал
• в конфигах мы прописываем sas токен для event hub — он почти не отличается по формату от того, что мы генерировали для первого сценария (и генерируется тем же кодом или сниппетом)

linux_publicSettings.json:
  {
    "StorageAccount": "<your storage account>",
    "sampleRateInSeconds": 15,
    "ladCfg": {
        "diagnosticMonitorConfiguration": {
          "metrics": {
            "metricAggregation": [
              {
                "scheduledTransferPeriod": "PT1H"
              },
              {
                "scheduledTransferPeriod": "PT1M"
              }
            ],
            "resourceId": "/subscriptions/<subscription id>/resourceGroups/<resource group>/providers/Microsoft.Compute/virtualMachines/<vm name>"
          }
        }
      },
    "fileLogs": [
      {
        "file": "/<path>/<to>/<log file>",
        "sinks": "LinuxEH"
      }
    ]
  }

{
    "storageAccountName" : "<your storage account>",
    "storageAccountSasToken": "<sas token for storage account - generate it on the portal>",
    "sinksConfig": {
      "sink": [
        {
          "name": "LinuxEH",
          "type": "EventHub",
          "sasURL": "https://<event hub namespace>.servicebus.windows.net/<event hub>?sr=xxxxxx&sig=yyyy&se=zzzz&skn=<policy name>"
        }
      ]
    }
}

Настройка Stream Analytics
В Stream Analytics джобе настраивается input с EventHub с параметрами
Event serialization format = JSON, Encoding = UTF-8, Event compression type = None
При этом доступ к данным, которые логируются, не такой простой. Если мы просто выполним select * from мы увидим примерно вот такую картину

т.е. нужны нам данные скрыты где-то в проперти json объекта, хранимого в поле PROPERTIES
Но и эту проблему в stream analytics можно решить красиво (да, мне очень нравится эта штука :)), например вот таким запросом

with events as (
 select UDF.to_json(properties.MSG) as obj
 from ehtest
)

select obj.* from events

где UDF.to_json — это написанная нами функция по конвертации строки в JSON объект (да, там ещё и функции можно писать, на javascript...)

В результате мы получаем простой доступ к данным лога

В заключение

Надеюсь, эта статья окажется кому-нибудь полезна.
Мне она уже принесла большую пользу, т.к. только с помощью реализации практических кейсов можно реально понять возможности и зрелость той или иной технологии.
Если вдруг я какие-нибудь сценарии упустил — напишите пожалуйста об этом в комментах.

Автор: Потураев Андрей

Источник