Журналы: формат, сбор, хранение

Место в цепочке

Что предыдущее звено обязано обеспечить: ограничение размера журналов Docker (max-size, max-file в /etc/docker/daemon.json, см. Docker). Без него журналы занимают весь диск раньше, чем до них дойдёт сборщик.

Что этот документ оставляет следующему: единая точка поиска и сквозной идентификатор запроса. Разбор отказа (симптом → слой → причина) описан в документе о метриках; здесь даётся то, чем выполняется его третий шаг.

Формат записи

Структурой, а не строкой. Запись — набор полей, а не предложение: так по ней можно искать и считать.

{"level":"error","msg":"payment declined","request_id":"7f3c…","user_id":42,"provider_code":"51"}

В примере показана смысловая часть записи. Поля ts, service и version добавляет настройка журналирования одинаково ко всем записям — в коде их не пишут.

Обязательные поля в каждой записи:

Переменная часть выносится в отдельные поля (user_id, provider_code, duration_ms), а не вписывается в msg. Запись "msg":"payment declined for user 42" не даёт посчитать, сколько отказов было всего: у каждой записи текст свой.

Уровни по назначению:

Сквозной идентификатор запроса. Идентификатор присваивается на входе (шлюз) и передаётся дальше по цепочке в заголовке. По нему собирается вся история одного обращения через все сервисы — без него разбор в распределённой системе превращается в сопоставление по времени.

Чего в журналах не должно быть: паролей, токенов, ключей, номеров карт, содержимого документов. Журналы читает больше людей, чем базу, и хранятся они в других местах. Идентификатор — можно, значение — нет.

Где это объявляется

По BMBP настройка журналирования — в shared/logging: от неё не зависит ни один слой, и формат задаётся один раз на сервис. Присвоение request_id и запись строки о завершении запроса — в посреднике (middleware) слоя api, рядом с подсчётом метрик.

Вывод — в стандартный поток, а не в файл внутри контейнера. Файл внутри контейнера означает, что сервис сам занимается ротацией, том и права становятся его заботой, а при пересоздании контейнера записи исчезают. В стандартный поток пишет и сборщик, и docker compose logs — второй способ остаётся рабочим при любых проблемах с хранилищем.

Одна запись — одна строка. Сборщик разбивает поток по переводу строки, поэтому многострочный след стека превращается в десяток бессвязных записей. Стек кладётся полем внутрь той же записи ("stack":"...").

Набор инструментов

Роли те же, что у метрик: сбор и хранение. Набор — один из рабочих, не единственный; критерий выбора прежний: ставится контейнером рядом с приложением и не требует внешней службы.

for i in grafana/alloy:v1.9.0 grafana/loki:3.5.0; do
  docker manifest inspect "$i" >/dev/null 2>&1 && echo "есть  $i" || echo "НЕТ   $i"
done

Ожидается: две строки есть. Если тега нет — возьмите ближайший выпущенный и запишите его в compose.yml.

Шаг 1. Хранилище

cd /opt/app/observability && mkdir -p loki alloy

# loki/loki.yml
auth_enabled: false               # разграничение по клиентам не используется: установка одна

server:
  http_listen_port: 3100
  log_level: warn                 # иначе хранилище журналов становится источником журналов

common:
  path_prefix: /loki
  storage:
    filesystem:
      chunks_directory: /loki/chunks
      rules_directory: /loki/rules
  replication_factor: 1
  ring:
    kvstore:
      store: inmemory

schema_config:
  configs:
    - from: 2024-01-01
      store: tsdb
      object_store: filesystem
      schema: v13
      index:
        prefix: index_
        period: 24h

limits_config:
  retention_period: 336h          # 14 суток
  reject_old_samples: true
  reject_old_samples_max_age: 168h
  ingestion_rate_mb: 8            # предел на приём: один сервис в цикле не займёт весь диск
  ingestion_burst_size_mb: 16

compactor:
  working_directory: /loki/compactor
  retention_enabled: true         # без этой строки срок хранения не применяется
  delete_request_store: filesystem

Добавьте в compose.yml рядом с сервисами набора метрик:

# compose.yml — записи добавляются в существующие разделы, а не новым файлом
volumes:
  loki_data:
  alloy_data:

services:
  loki:
    image: grafana/loki:3.5.0
    restart: unless-stopped
    command: ["-config.file=/etc/loki/loki.yml"]
    volumes:
      - ./loki/loki.yml:/etc/loki/loki.yml:ro
      - loki_data:/loki
    ports: ["127.0.0.1:3100:3100"]     # только с этой машины
    networks: [obs_net]

docker compose up -d loki

curl -s -o /dev/null -w '%{http_code}\n' http://127.0.0.1:3100/ready

Ожидается: 200. Первые полминуты после запуска возвращается 503 с текстом о том, что приёмник не готов, — это штатное состояние запуска, а не отказ.

Шаг 2. Сбор из контейнеров

// alloy/config.alloy

// какие контейнеры существуют
discovery.docker "containers" {
  host             = "unix:///var/run/docker.sock"
  refresh_interval = "10s"
}

// какие метки поставить каждому потоку
discovery.relabel "containers" {
  targets = discovery.docker.containers.targets

  rule {                                   // имя контейнера приходит с ведущим слэшем
    source_labels = ["__meta_docker_container_name"]
    regex         = "/(.*)"
    target_label  = "container"
  }
  rule {
    source_labels = ["__meta_docker_container_label_com_docker_compose_service"]
    target_label  = "service"
  }
  rule {
    source_labels = ["__meta_docker_container_label_com_docker_compose_project"]
    target_label  = "project"
  }
}

// чтение вывода контейнеров
loki.source.docker "containers" {
  host       = "unix:///var/run/docker.sock"
  targets    = discovery.relabel.containers.output
  labels     = { job = "docker" }
  forward_to = [loki.process.app.receiver]
}

loki.process "app" {
  stage.json {                             // разбор JSON-записи
    expressions = { level = "level" }
  }

  stage.labels {                           // меткой становится только уровень
    values = { level = "" }
  }

  stage.drop {                             // отладочные записи не хранятся
    source = "level"
    value  = "debug"
  }

  stage.replace {                          // страховка от секретов, а не замена дисциплине
    expression = "(?i)(?:authorization|bearer|password|secret)[=: ]+\\S+"
    replace    = "скрыто"
  }

  forward_to = [loki.write.default.receiver]
}

loki.write "default" {
  endpoint {
    url = "http://loki:3100/loki/api/v1/push"
  }
}

# compose.yml, раздел services
  alloy:
    image: grafana/alloy:v1.9.0
    restart: unless-stopped
    command:
      - run
      - --storage.path=/var/lib/alloy/data      # отметки прочитанного переживают перезапуск
      - /etc/alloy/config.alloy
    volumes:
      - ./alloy/config.alloy:/etc/alloy/config.alloy:ro
      - /var/run/docker.sock:/var/run/docker.sock:ro
      - alloy_data:/var/lib/alloy/data
    networks: [obs_net]
    depends_on: [loki]

Метки — то же, что в метриках: их мало. Каждое сочетание значений меток — отдельный поток в хранилище, и большое число потоков замедляет и приём, и поиск. Меткой становится то, по чему отбирают целиком (service, level, container), а request_id и идентификаторы остаются полями внутри записи: по ним ищут фильтром, и это дешевле.

Сокет Docker. Он смонтирован на чтение, но это не делает доступ безопасным: через сокет запускается контейнер с примонтированным корнем хоста, то есть доступ равносилен правам root (см. Docker). Отсюда правило: в этот контейнер ставится образ с закреплённой версией, и он не собирается из чужого файла образа.

Альтернатива без сокета — драйвер журналирования Docker, отправляющий записи в хранилище напрямую. Доступ к сокету он снимает, но при недоступном хранилище записи теряются либо запись в контейнере блокируется. При сборе через сокет они дожидаются в файле на хосте — это и есть причина выбора.

docker compose up -d alloy

Проверка — метки появились, значит записи дошли:

curl -s http://127.0.0.1:3100/loki/api/v1/labels
curl -s 'http://127.0.0.1:3100/loki/api/v1/label/service/values'

Ожидается: "status":"success" и перечень меток, среди которых service, level, container; во втором ответе — имена сервисов. Пустой перечень означает, что записи не поступают: смотрите docker compose logs alloy.

Шаг 3. Поиск

Источник данных подключается тем же файлом, что и Prometheus:

# grafana/provisioning/datasources/datasources.yml — добавить в конец списка
  - name: Loki
    uid: loki
    type: loki
    access: proxy
    url: http://loki:3100

docker compose restart grafana

Запросы, которые закрывают разбор:

curl -sG http://127.0.0.1:3100/loki/api/v1/query_range \
  --data-urlencode 'query={service="backend"} | json | level="error"' \
  --data-urlencode 'limit=5' \
  --data-urlencode "start=$(date -u -d '1 hour ago' +%s)000000000" \
  --data-urlencode "end=$(date -u +%s)000000000" | head -c 400; echo

Ожидается: "status":"success" и непустой "result", если ошибки за час были. Ответ "result":[] при заведомо имевшихся ошибках означает, что метка service проставлена другим значением — сверьте со списком из шага 2.

Шаг 4. Ротация и срок хранения

Ограничения стоят в трёх местах, и каждое решает свою задачу:

Файл на хосте — это буфер: пока сборщик недоступен, записи ждут в нём. Его размер — произведение max-size на max-file, в настройке из документа о Docker это 30 МБ на контейнер. На какое время хватает буфера, считается делением этого числа на суточный объём записей (измеряется ниже). Когда буфер заполнен, самые старые записи перезаписываются: диск сервера приложения не резервируется под журналы, и это осознанный размен.

Срок хранения назначается от того, как поздно обнаруживается ошибка. Две недели покрывают случай «заметили в понедельник то, что началось на прошлой неделе». Больший срок стоит места: журналы растут быстрее всего остального в системе.

Объём измеряется, а не оценивается. Через неделю работы:

docker system df -v | grep -E 'VOLUME|loki_data'

Полученный размер, поделённый на число суток и умноженный на срок хранения, даёт нужное место. Если оно больше доступного — уменьшают срок или отбрасывают сборщиком то, что не читают: записи уровня info от служебных опросов, обращения проверок готовности.

Шаг 5. Секретов в журналах нет

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

val=$(grep -m1 '^JWT_SIGNING_KEY=' /opt/app/backend/.secrets/.env | cut -d= -f2-)

curl -sG http://127.0.0.1:3100/loki/api/v1/query_range \
  --data-urlencode "query={job=\"docker\"} |= \"$val\"" \
  --data-urlencode "start=$(date -u -d '24 hours ago' +%s)000000000" \
  --data-urlencode "end=$(date -u +%s)000000000" | grep -cF "$val"

Ожидается: 0. Ненулевой результат означает утечку: значение считается раскрытым, его отзывают и заменяют (порядок — в документе о секретах), и только потом убирают причину записи.

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

• логируется тело запроса или ответа целиком;
• логируются настройки при старте сервиса;
• в текст непредвиденной ошибки попадает строка подключения (её печатает драйвер базы).

Правило stage.replace из шага 2 закрывает часть случаев, но полагаться на него нельзя: оно ищет известные формы записи, а строка подключения или тело запроса под них не подходят. Отсутствие секрета обеспечивается на стороне приложения — списком полей, которые в журнал не выводятся.

sudo ss -ltnp | grep :3100        # ожидается: 127.0.0.1:3100
curl -m 5 -I http://example.com:3100    # с другой машины: ожидается таймаут или отказ

Открытое наружу хранилище журналов — это доступ к переписке системы: в записях видны маршруты, идентификаторы, тексты ошибок, имена сервисов. Закрывается оно тем же способом, что остальные внутренние службы: наружу не публикуется вовсе, а для просмотра есть Grafana через SSH-туннель (см. документ о метриках, шаг 4).

От графика к записи

Порядок разбора описан в документе о метриках. Журналы закрывают его третий шаг, и на практике это три действия:

1. по графику доли ошибок определяется время начала;
2. запрос sum by (service, level) (count_over_time({project="app"}[5m])) за тот же период показывает, у какого сервиса всплеск;
3. первая запись уровня error из этого сервиса даёт request_id, по которому собирается вся история обращения: {project="app"} |= "<request_id>".

Если на третьем шаге request_id в записи нет, разбор останавливается на сопоставлении по времени — это и есть цена его отсутствия.

Типичные отказы

Откат и снятие

cd /opt/app/observability
docker compose stop alloy             # сбор прекращается, хранилище остаётся доступным
docker compose rm -sf alloy loki      # убрать оба сервиса; тома остаются
docker volume rm observability_loki_data     # удалить собранные записи — отдельным действием

Что при этом не затрагивается: журналы самих контейнеров. Они лежат на хосте в файлах Docker и читаются как обычно:

cd /opt/app/backend && docker compose logs --tail=200 backend

Приложение, его тома и настройка журналирования тоже не задеты: сбор — отдельные контейнеры в отдельном проекте Compose. Формат записи и request_id остаются в приложении и после снятия сбора — они полезны и при чтении вывода контейнера напрямую.