Logs analysis

https://habr.com/ru/articles/749714/

journalctl - Работа со структурированными логами

Журнал событий, это компонент systemd, который захватывает сообщения Syslog, логи ядра, все события при инициализации системы (RAM, диск, boot, STDOUT/STDERR для всех сервисов), индексирует их и затем предоставляет удобной пользовательский интерфейс для поиска и фильтрации логов. Журнал (systemd journal) можно использовать вместе или вместо syslog или syslog-ng.

Утилита командной строки journalctl, если сравнивать ее с традиционным инструментами для работы с логами в UNIX (tail, grep, sed, awk) более широкие возможности.

Давайте рассмотрим основные возможности которые предоставляет журнал systemd и способы их применения.

Журнал systemd сохраняется на диск, поэтому все логи «переживают» перезагрузку системы. Посмотреть список с доступными загрузками:

journalctl --list-boots |head -n2

journalctl --list-boots |tail -n2

Команда journalctl –b покажет все логи для текущей загрузки. Если необходимы логи какого-то определенного периода, то нужно добавить в качестве аргумента номер загрузки:

journalctl -b -1

Для того, чтобы получить все логи для текущей загрузки в обратном хронологическом порядке:

journalctl -b --all --catalog --no-pager

Все логи за все время в одном файле:

journalctl --all --catalog --merge --no-pager

Текущая загрузка, только логи ядра:

journalctl -b -k --no-pager

Для того, чтобы можно было отслеживать логи в режиме реального времени (похоже на tail –f):

journalctl -f

Просмотреть сколько места занимают журналы systemd на диске (/var/log/journal/):

journalctl --disk-usage

Получить логи и метаданные:

journalctl --output verbose

Экспорт логов в файл:

journalctl --output export > export.log

Фильтрация логов

Можно фильтровать логи по приоритету (RFC 5424 6.2.1):

journalctl -f -p emerg
journalctl -f -p alert
journalctl -f -p crit
journalctl -f -p err
journalctl -f -p warning
journalctl -f -p notice
journalctl -f -p info
journalctl -f -p debug

Вывести только логи c приоритетом error, critical и alert:

journalctl -p err..alert

Логи только для определенного идентификатора:

journalctl -t NetworkManager

journalctl можно использовать вместе с стандартными инструментами командной строки - grep, awk:

journalctl -b | grep -i selinux

Для того, чтобы сократить время лучше использовать флаг -g или --grep:

journalctl -g nginx

journalctl -b -g kube

journalctl -g fail --case-sensitive=true

Как и grep --grep «понимает» регулярные выражения:

journalctl --grep '(Started|Stopping)'

Позволяет отфильтровывать логи по временным штампам, без grep, awk и sed. Не нужно запоминать сложные регулярные выражения:

journalctl --since "20 min ago"

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

journalctl --since "2023-06-21 14:24 Pacific/Auckland" --until "2023-06-21 14:30 Europe/Amsterdam"

Журнал systemd сохраняет логи в структурированном формате:

journalctl -o verbose --no-pager

Sat 2023-07-22 17:17:40.468870 MSK [s=8e997e4278d4420da4ee36deb1bcb537;i=48abc;b=200a318f51b04680a1207f58ed5aaf88;m=2199c4e719;t=601140b4770a0;x=59dabeebe46afe51]
    _TRANSPORT=syslog
    PRIORITY=6
    SYSLOG_IDENTIFIER=sshd
    _UID=0
    _GID=0
    _COMM=sshd
    _EXE=/usr/sbin/sshd
    _CAP_EFFECTIVE=1ffffffffff
    _SELINUX_CONTEXT=system_u:system_r:sshd_t:s0-s0:c0.c1023
    _SYSTEMD_CGROUP=/system.slice/sshd.service
    _SYSTEMD_UNIT=sshd.service
    _SYSTEMD_SLICE=system.slice
    _SYSTEMD_INVOCATION_ID=2c28dd046868493ca6c4ae9325b237b9
    _BOOT_ID=200a318f51b04680a1207f58ed5aaf88
    _MACHINE_ID=b0900a09b82b4ecca86af861e99e64c5
    _HOSTNAME=Pythagoras
    _RUNTIME_SCOPE=system
    SYSLOG_FACILITY=10
    _CMDLINE="sshd: unknown [priv]"
    SYSLOG_PID=1339341
    _PID=1339341
    SYSLOG_TIMESTAMP=Jul 22 17:17:40
    MESSAGE=Connection closed by invalid user ubuntu 45.95.147.231 port 53778 [preauth]

Журнал systemd сохраняет логи в структурированном формате:

journalctl _PID=1339341

Или например посмотреть логи всех программ написанных на питоне:

journalctl _COMM=python

JSON - новые возможности для автоматизации

journalctl умеет выводить логи в формате json – можно использовать утилиту jq для фильтрации сообщений:

journalctl --since "1500 min ago" -u kubelet.service -o json | jq .""_CMDLINE""

"/usr/bin/kubelet --bootstrap-kubeconfig=/etc/kubernetes/bootstrap-kubelet.conf --kubeconfig=/etc/kubernetes/kubelet.conf --config=/var/lib/kubelet/config.yaml --container-runtime-endpoint=unix:///run/containerd/containerd.sock --node-ip=<IP_ADDRESS> --node-labels=<LABEL>/cluster=true, --pod-infra-container-image=registry.k8s.io/pause:3.9"
"/usr/bin/kubelet --bootstrap-kubeconfig=/etc/kubernetes/bootstrap-kubelet.conf --kubeconfig=/etc/kubernetes/kubelet.conf --config=/var/lib/kubelet/config.yaml --container-runtime-endpoint=unix:///run/containerd/containerd.sock --node-ip=<IP_ADDRESS> --node-labels=<LABEL>/cluster=true, --pod-infra-container-image=registry.k8s.io/pause:3.9"
"/usr/bin/kubelet --bootstrap-kubeconfig=/etc/kubernetes/bootstrap-kubelet.conf --kubeconfig=/etc/kubernetes/kubelet.conf --config=/var/lib/kubelet/config.yaml --container-runtime-endpoint=unix:///run/containerd/containerd.sock --node-ip=<IP_ADDRESS> --node-labels=<LABEL>/cluster=true, --pod-infra-container-image=registry.k8s.io/pause:3.9"

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

В качестве наглядного примера можно представить себе сдающий сценарий: Приложение X записывает в журнал событий какие-то сообщения. Простая программа работающая в режиме демона Linux отслеживает события в журнале systemd. В случае появления какого-то определенного сообщения в журнале, программа следуя внутренней логике отправляет сообщение в шину данных (kafka, rabbitmq, NATS) или выполняет определенные операции в системе:

Код

package main

import (
        "bufio"
        "fmt"
        "os"
        "os/exec"
        "strings"
)

func main() {
        // Отслеживаем сообщения для идентификатора «events_topic»
        cmdName := "journalctl -t events_topic -f"
        cmdArgs := strings.Fields(cmdName)

        cmd := exec.Command(cmdArgs[0], cmdArgs[1:len(cmdArgs)]...)
        stdout, _ := cmd.StdoutPipe()
        cmd.Start()
        oneByte := make([]byte, 100)
        num := 1
        for {
                _, err := stdout.Read(oneByte)
                if err != nil {
                        fmt.Printf(err.Error())
                        break
                }
                r := bufio.NewReader(stdout)
                line, _, _ := r.ReadLine()
                fmt.Println(string(line))
                num = num + 1
                if num > 3 {
                        os.Exit(0)
                }
        }
}

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

go run watch.go
Jul 22 15:49:25 Pythagoras events_topic[1293240]: NEW EVENT
Jul 22 15:49:28 Pythagoras events_topic[1293250]: NEW EVENT

А в другой сессии терминала эмулируем запись приложением X сообщений в журнал с помощью встроенной утилиты systemd-cat:

echo "NEW EVENT" | systemd-cat -t events_topic
echo "NEW EVENT" | systemd-cat -t events_topic

В данном случае для работы с журналом используется пакет "os/exec" – то есть мы выполняем системные команды, но можно воспользоваться одной из существующих библиотек:

https://github.com/coreos/go-systemd

Это простой пример использования структурированных логов журнала systemd. Возможности systemd гораздо шире – многие из них используются, например облачными провайдерами для построения отказоустойчивой инфраструктуры.

sos report - когда нужно найти иголку в стоге сена

https://github.com/sosreport/sos

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

Для таких сценариев как раз и предназначен sos report. Это унифицированный инструмент для сбора логов и диагностической информации. С помощью sos report можно создавать архив со всей необходимой информацией о системе – эти данные используются для анализа и поиска проблем в режиме оффлайн.

Установка sosreport:

yum install sos

apt install sosreport

Программа написана Python. Легко расширяется. Для sos report были написаны десятки плагинов:

sos report --list-plugins

alternatives         System alternatives
anaconda             Anaconda installer
anacron              Anacron job scheduling service
ata                  ATA and IDE information
auditd               Audit daemon information
block                Block device information
boot                 Bootloader information
cgroups              Control groups subsystem
chrony               Chrony clock (for Network time protocol)
cockpit              Cockpit Web Service
conntrack            conntrack - netfilter connection tracking
 ...

профилей:

sos report --list-profiles

boot            boot, devices, dracut, grub2, services, systemd, udev
cluster         conntrack
container       cgroups, containers_common, podman, selinux
 ...

и пресетов:

sos report --list-presets
       name: none
description: Do not load a preset
       note: Use to disable automatically loaded presets

       name: minimal
description: Small and quick report that reduces sos report resource consumption
       note: May be useful for low-resource systems, but may not provide sufficient data for analysis

Все это можно кастомизировать под определенный кейс.

Пример генерации репорта:

sos report --all-logs --batch --tmp-dir=/var

Созданный архив с логами можно забрать для дальнейшего анализа:

Your sosreport has been generated and saved in:
	/var/tmp/<FILENAME>.tar.xz

Size	20.25MiB
Owner	root
sha256	db71d185550428b5c3a12010fc76206b58b159671c6b74c2fce575254e388030

В зависимости от выбранного профиля и плагинов, в архиве может содержатся подробная диагностическая информация с выводами различных утилит и инструментов:

tar -xf <FILENAME>.tar.xz

boot  dmidecode    free            ip_addr   lib    lspci    proc    root-symlinks  sos_logs     uname   var
date  environment  hostname        ip_route  lsmod  mount    ps      run            sos_reports  uptime  version.txt
df    etc          installed-rpms  last      lsof   netstat  pstree  sos_commands   sys          usr     vgdisplay

При генерации репорта, с помощью флагов --clean, --domains и --keywords можно обфусцирвоать (подчистить) полученный архив удалив всю конфиденциальную информацию.