Связывание данных логов с трассировками

Материал из Документация Ключ-АСТРОМ

Связывание данных логов с трассировками

Ключ-АСТРОМ может обогащать загруженные данные логов дополнительной информацией, которая помогает распознавать, коррелировать и оценивать данные. Обогащение логов приводит к более точному анализу логов. Обогащение логов позволяет:

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

Автоматическое обогащение логов

Вы можете включить обогащение логов для конкретной технологии, используемой для создания данных логов, и позволить Ключ-АСТРОМ автоматически внедрять дополнительные атрибуты в каждую получаемую запись лога. Этот метод рекомендуется для структурированных данных логов известных технологий.

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

Включение/отключение обогащения логов для конкретной технологии

Чтобы включить обогащение логов для конкретной технологии:

  1. Перейдите в Настройки и выберите Настройки > Функции ЕдиногоАгента.
  2. Отфильтруйте по обогащению.
  3. Включите/отключите обогащение логов для каждой технологии, которую вы используете для создания загружаемых данных логов.
  4. Выберите Сохранить изменения, чтобы сохранить конфигурацию.

Что делает автоматическое обогащение логов

Обогащение логов изменяет загруженные данные логов и добавляет следующую информацию в каждую обнаруженную запись лога:

  • dt.trace_id
  • dt.span_id
  • dt.entity.process_group_instance

Поддерживаемые фреймворки

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

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

Для структурированных данных логов, таких как JSON, XML и хорошо определённые текстовые форматы логов, Ключ-АСТРОМ добавляет поле атрибута в запись лога.

Пример обогащённых данных логов в формате JSON

Данные логов в формате JSON обогащаются дополнительными свойствами dt.trace_id, dt.span_id и dt.entity.process_group_instance.

{
  "severity": "error",
  "time": 1638957438023,
  "pid": 1,
  "hostname": "paymentservice-788946fdcd-42lgq",
  "name": "paymentservice-charge",
  "dt.trace_id": "d04b42bc9f4b6ecdbf6bc9f4b6ecdbc",
  "dt.span_id": "9adc716eb808d428",
  "dt.entity.process_group_instance": "PROCESS_GROUP_INSTANCE-27204EFED3D8466E",
  "message": "Unsupported card type for cardNumber=************0454"
}

Пример обогащённых данных логов в формате XML

Данные логов в формате XML обогащаются дополнительными узлами dt.trace_id, dt.span_id и dt.entity.process_group_instance.

<?xml version="1.0" encoding="windows-1252" standalone="no"?><record>
<date>2021-08-24T14:41:36.565218700Z</date>
<millis>1629816096565</millis>
<nanos>218700</nanos>
<sequence>0</sequence>
<logger>com.apm.testapp.logging.jul.XMLLoggingSample</logger>
<level>INFO</level>
<class>com.apm.testapp.logging.jul.BaseLoggingSample</class>
<method>info</method>
<thread>1</thread>
<message>Update completed successfully.</message>
<dt.trace_id>513fcd4e9b08792fcd4e9b08792</dt.trace_id>
<dt.span_id>125840e3125840e3</dt.span_id>
<dt.entity.process_group_instance>PROCESS_GROUP_INSTANCE-27204EFED3D8466E</dt.entity.process_group_instance></record>

Неструктурированные данные логов

Проверьте, влияет ли обогащение логов Ключ-АСТРОМ на ваш существующий конвейер данных логов, прежде чем использовать автоматическое обогащение логов для неструктурированных данных логов. Чтобы избежать обогащения логов из тестовых или симуляционных запусков, рекомендуется исключать процессы, содержащие --dry-run. Например, сервер приложений Payara использует стартовые скрипты с такими сухими запусками, и сервер может не запуститься корректно, если это исключение не установлено.

Неструктурированные данные логов обычно состоят из необработанного простого текста, который упорядочен последовательно и предназначен для чтения людьми. Ключ-АСТРОМ не обогащает неструктурированные данные логов автоматически. Ключ-АСТРОМ может обогащать неструктурированные данные логов, но добавление дополнительной информации к данным логов может повлиять на сторонние инструменты, которые потребляют те же данные логов.

Пример обогащённых данных логов в формате необработанного текста

Данные логов в необработанном тексте обогащаются дополнительной строкой [!dt dt.trace_id=$trace_id, dt.span_id=$span_id, dt.entity.process_group_instance=$dt.entity.process_group_instance] (атрибуты и их значения).

127.0.0.1 - [21/Oct/2021:10:33:28 +0200] GET /index.htm HTTP/1.1 404 597 [!dt dt.trace_id=aa764ee37ebaa764ee37eaa764ee37e,dt.span_id=b93ede8b93ede8, dt.entity.process_group_instance=PROCESS_GROUP_INSTANCE-27204EFED3D8466E]

Ручное обогащение логов

Версия ЕдиногоАгента 1.239+

Вы можете вручную обогащать загруженные данные логов Ключ-АСТРОМ, определив шаблон лога, включающий поля dt.span_id, dt.trace_id, dt.trace_sampled и dt.entity.process_group_instance. Вы можете включить ручное обогащение логов для конкретной технологии, следуя шагам обогащения логов. Обязательно соблюдайте следующие правила для формата обогащаемых полей в неструктурированном логе:

  • Поля должны быть заключены в квадратные скобки ([]) с префиксом !dt. Например, [!dt dt.trace_id=$dt_trace_id,dt.span_id=$dt_span_id, dt.entity.process_group_instance=$dt.entity.process_group_instance]
  • Поля должны быть отформатированы без двойных кавычек.
  • Любые недопустимые символы для поля и значения поля должны быть экранированы.
  • Любые управляющие символы, такие как \n, должны быть исключены из определения обогащения.

Пример ручного обогащения данных логов NGINX

Предположим, вы хотите вручную обогатить данные логов NGINX полями dt.trace_id, dt.span_id и dt.trace_sampled. Файл конфигурации NGINX содержит множество стандартных переменных NGINX, ваше определение формата лога должно находиться в секции log_format. Например:

log_format custom '$remote_addr - [$time_local] $request $status $body_bytes_sent [!dt dt.trace_id=$dt_trace_id,dt.span_id=$dt_span_id,dt.trace_sampled=$dt_trace_sampled]';
access_log logs/access.log custom;

Результатом будет файл access.log, содержащий обогащённые записи логов:

127.0.0.1 - [22/Mar/2022:08:50:45 +0100] GET /index.htm HTTP/1.1 200 30 [!dt dt.trace_id=b9e5c9ec08be5fab5071d76f427be7da,dt.span_id=43c5bb9432593963,dt.trace_sampled=true]
127.0.0.1 - [22/Mar/2022:08:50:45 +0100] GET /index.htm HTTP/1.1 200 30 [!dt dt.trace_id=01e52950b145d97bf22345e68c5e6c58,dt.span_id=de819d856eecb236,dt.trace_sampled=true]

Для ЕдиногоАгента версии 1.237 и более ранних используемые переменные NGINX отличаются. Например:

log_format custom '$remote_addr - [$time_local] $request $status $body_bytes_sent [!dt dt.trace_id=$trace_id,dt.span_id=$span_id]';
access_log logs/access.log custom;

Результатом будет файл access.log, содержащий обогащённые записи логов:

127.0.0.1 - [21/Oct/2021:10:33:28 +0200] GET /index.htm HTTP/1.1 404 597 [!dt dt.trace_id=e1c0afeb0b8a91d7748139aa764ee37e,dt.span_id=e5e6748fab93ede8]
127.0.0.1 - [21/Oct/2021:10:33:31 +0200] GET /index.html HTTP/1.1 200 1056 [!dt dt.trace_id=81fe7816ba6c38f7aa09aef3684cd941,dt.span_id=3bdacc466ae073cd]

Если вы используете фреймворк логирования и форматировщик логов, который позволяет задавать пользовательские шаблоны логов, вы можете адаптировать шаблон в форматировщике логов и напрямую обращаться к атрибутам обогащения Ключ-АСТРОМ.

Пример ручного обогащения данных логов Log4j

В PatternFormatter Log4j можно указать такой шаблон, чтобы включить информацию обогащения Ключ-АСТРОМ:

<PatternLayout pattern="%d{HH:mm:ss.SSS} [%t] %-5level %logger{36} dt.trace_id=%X{dt.trace_id} dt.span_id=%X{dt.span_id} dt.entity.process_group_instance=%X{dt.entity.process_group_instance} - %msg%n"/>

Пример ручного обогащения Logstash Logback encoder

Logback — преемник проекта log4j. Logstash Logback — расширение, предоставляющее кодировщики, макеты и аппендеры для логирования в JSON и других форматах, поддерживаемых Jackson. Ниже приведён пример ручного обогащения с использованием кодировщика Logstash. Обратите внимание на дополнительное свойство mdc в файле конфигурации, где можно указать переменные MDC.

<appender name="COMPOSITEJSONENCODER" class="ch.qos.logback.core.FileAppender">
  <file>compositejsonencoder.log</file>
  <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
    <providers>
      <timestamp>
        <fieldName>timestamp</fieldName>
        <timeZone>UTC</timeZone>
      </timestamp>
      <loggerName>
        <fieldName>logger</fieldName>
      </loggerName>
      <logLevel>
        <fieldName>level</fieldName>
      </logLevel>
      <threadName>
        <fieldName>thread</fieldName>
      </threadName>
      <mdc>
        <includeMdcKeyName>dt.span_id</includeMdcKeyName>
        <includeMdcKeyName>dt.trace_id</includeMdcKeyName>
        <includeMdcKeyName>dt.entity.host</includeMdcKeyName>
      </mdc>
      <stackTrace>
        <fieldName>stackTrace</fieldName>
        <!-- maxLength - limit the length of the stack trace -->
        <throwableConverter class="net.logstash.logback.stacktrace.ShortenedThrowableConverter">
          <maxDepthPerThrowable>200</maxDepthPerThrowable>
          <maxLength>14000</maxLength>
          <rootCauseFirst>true</rootCauseFirst>
        </throwableConverter>
      </stackTrace>
      <message />
      <throwableClassName>
        <fieldName>exceptionClass</fieldName>
      </throwableClassName>
    </providers>
  </encoder>
</appender>

Пример ручного обогащения данных логов .NET Serilog

В .NET Serilog вы можете настраивать шаблоны вывода для текстовых приёмников, таких как консольные или файловые, чтобы включить информацию обогащения Ключ-АСТРОМ.

{Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} [{Level:u3}] [!dt dt.trace_id={trace_id}, dt.span_id={span_id}, dt.trace_sampled={trace_sampled}] {Message:lj}{NewLine}{Exception}

NGINX ingress с Kubernetes

Вы можете обогащать логи с помощью NGINX ingress в Kubernetes в два шага:

  1. Выполните инструкции по инструментированию ingress-nginx на Kubernetes.
  2. Добавьте команду ниже в файл configmap.yaml для NGINX ingress. Добавление строки main-snippet включает загрузку через ЕдиныйАгент и необязательно, если вы уже следовали инструкциям по ручному инструментированию.
main-snippet: load_module /opt/astromkey/oneagent/agent/bin/current/linux-musl-x86-64/liboneagentnginx.so;log-format-upstream: '$remote_addr - $remote_user [$time_local] "$request" [!dt dt.trace_id=$dt_trace_id,dt.span_id=$dt_span_id,dt.trace_sampled=$dt_trace_sampled] $status $body_bytes_sent "$http_referer" "$http_user_agent" $request_length'

Пример файла configmap.yaml

apiVersion: v1
kind: Namespace
metadata:
  name: prod-ingress-nginx
  labels:
    app.kubernetes.io/name: ingress-nginx
    app.kubernetes.io/instance: ingress-nginx
---
# Source: ingress-nginx/templates/controller-serviceaccount.yaml
apiVersion: v1
kind: ServiceAccount
metadata:
  labels:
    helm.sh/chart: ingress-nginx-4.0.6
    app.kubernetes.io/name: ingress-nginx
    app.kubernetes.io/instance: ingress-nginx
    app.kubernetes.io/version: 1.0.4
    app.kubernetes.io/managed-by: Helm
    app.kubernetes.io/component: controller
  name: ingress-nginx
  namespace: prod-ingress-nginx
automountServiceAccountToken: true
---
# Source: ingress-nginx/templates/controller-configmap.yaml
apiVersion: v1
kind: ConfigMap
metadata:
  labels:
    helm.sh/chart: ingress-nginx-4.0.6
    app.kubernetes.io/name: ingress-nginx
    app.kubernetes.io/instance: ingress-nginx
    app.kubernetes.io/version: 1.0.4
    app.kubernetes.io/managed-by: Helm
    app.kubernetes.io/component: controller
  name: ingress-nginx-controller
  namespace: prod-ingress-nginx
data:
  allow-snippet-annotations: 'true'
  main-snippet: load_module /opt/astromkey/oneagent/agent/bin/current/linux-musl-x86-64/liboneagentnginx.so;
  log-format-upstream: '$remote_addr - $remote_user [$time_local] "$request" [!dt dt.trace_id=$dt_trace_id,dt.span_id=$dt_span_id,dt.trace_sampled=$dt_trace_sampled] $status $body_bytes_sent "$http_referer" "$http_user_agent" $request_length'
...

Получение ID спанов и трассировок

Чтобы Ключ-АСТРОМ мог сопоставлять логи с соответствующими трассировками, вы можете включать ID спанов и трассировок в сообщения логов, используя нотацию [!dt]. В следующих примерах показано, как получить ID спанов и трассировок с помощью OpenTelemetry или SDK ЕдиногоАгента:

В примере ниже создана функция dt_log для обогащения заданного сообщения лога информацией trace_id и span_id. Печать этого обогащённого сообщения в настроенный приёмник логов связывает сообщение лога с текущим активным спаном в веб-интерфейсе Ключ-АСТРОМ.

import logging
from opentelemetry import trace

def dt_log(self, record):
    if (not self.disabled) and self.filter(record):
        ctx = trace.get_current_span().get_span_context()
        if ctx.is_valid:
            trace_id = "{0:032X}".format(ctx.trace_id)
            span_id = "{0:016X}".format(ctx.span_id)
            record.msg = f"[!dt dt.trace_id={trace_id},dt.span_id={span_id}] - {record.msg}"
    self.callHandlers(record)

logging.Logger.handle = dt_log

def lambda_handler(event, context):
    logger = logging.getLogger()
    logger.warning("Hello world")
    return {
        "statusCode": 200,
        "body": "Hello from lambda"
    }

Получение ID экземпляра группы процессов

Вы можете получить поле dt.entity.process_group_instance с помощью команды OpenTelemetry Python, содержащей merged. Поле process_group_instance извлекается как один из атрибутов, передаваемых в merged, как показано в примере ниже:

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

import json
from opentelemetry import trace as OpenTelemetry
from opentelemetry.exporter.otlp.proto.http.trace_exporter import (
    OTLPSpanExporter,
)
from opentelemetry.sdk.resources import Resource
from opentelemetry.sdk.trace import TracerProvider, sampling
from opentelemetry.sdk.trace.export import (
    BatchSpanProcessor,
)

merged = dict()
for name in ["dt_metadata_e617c525669e072eebe3d0f08212e8f2.json", "/var/lib/astromkey/enrichment/dt_metadata.json"]:
    try:
        data = ''
        with open(name) as f:
            data = json.load(f if name.startswith("/var") else open(f.read()))
        merged.update(data)
    except:
        pass

merged.update({
    "service.name": "python-quickstart",  #TODO Replace with the name of your application
    "service.version": "1.0.1",  #TODO Replace with the version of your application
})

resource = Resource.create(merged)
tracer_provider = TracerProvider(sampler=sampling.ALWAYS_ON, resource=resource)
OpenTelemetry.set_tracer_provider(tracer_provider)
tracer_provider.add_span_processor(
    BatchSpanProcessor(OTLPSpanExporter(
        endpoint="http://localhost:14499/otlp/v1/traces"
    ))
)

При использовании ЕдиногоАгента обязательно включите публичный Контроллер выполнения расширений в настройках Ключ-АСТРОМ, иначе данные не будут отправляться. Перейдите в Настройки > Настройки > Контроллер выполнения расширений. Переключатели Включить контроллер выполнения расширений и Включить локальный API для метрик PIPE/HTTP и загрузки логов должны быть активны.

Ограничения

Если вы используете пользовательский форматировщик/транспорт winston (применимо только к Node.js), вам нужно вручную добавить ваши внедрённые dt.traceId и dt.spanId, как в примере ниже:

const winston = require("winston");
const Transport = require("winston-transport");

class CustomTransport extends Transport {
  log(info, next) {
    let myLogLine = `MyLogLine: ${info.timestamp} level=${info.level}: ${info.message}`;

    // this is important as above line only picks timestamp, level and message but nothing else from metadata
    if (info["dt.trace_id"]) {
      myLogLine = `[!dt dt.trace_id=${info["dt.trace_id"]},dt.span_id=${info["dt.span_id"]},dt.trace_sampled=${info["dt.trace_sampled"]}] ${myLogLine}`;
    }

    console.log(myLogLine);
    next();
  }
}

const logger = winston.createLogger({
  level: "info",
  format: winston.format.timestamp(),
  transports: [
    new CustomTransport(), // this transport includes all metadata (including astromkey added traceId,..)
    new winston.transport.Console({
      format: winston.format.simple()
    })
  ]
})