Розбір журналів подій: знайти справжню помилку (і надіслати собі електронний лист)

Було корисно?

О 02:13 ваш пейджер (або клієнт) каже, що щось не працює. Ви підключаєтеся по SSH, запускаєте journalctl -xe і бачите водоспад повідомлень, які всі виглядають однаково підозріло. Половина з них — «нормальні». Інша половина — «ненормальні, але не причина». Десь поміж ними є один рядок, який має значення: перша помилка, через яку почалось усе інше.

Це про те, як швидко знайти той рядок, довести, що він причинний (а не просто шум), і підключити результат до нудного, надійного сповіщення електронною поштою самому собі. Не хмарний «лог-аналітик» зі словами продажу. Практична звичка для продукції.

Практична ментальна модель: симптоми, тригери та перша «погана» подія

Журнали подій — це не наратив. Це натовп. Ваше завдання — знайти ту людину, яка завдала першого удару.

Три категорії, які треба розділяти

  • Симптоми: повторні спроби, таймаути, «connection reset», «failed to send», «context deadline exceeded», «upstream unavailable». Це вираження болю у сервісів, що залежать від вас.
  • Тригери: падіння процесу, закінчення терміну дії сертифіката, повторне монтування файлової системи в режимі «read-only», мережеві флапи, OOM kill ядра. Зазвичай вони ближчі до кореня проблеми.
  • Шум: періодичні перевірки здоров’я, cron, liveness probes, очікувані рестарти, debug-логи в продукції, попередження про застарілість. Шум не «неважливий»; просто зараз він не допомагає.

Коли люди кажуть «журнали занадто шумні», частіше за все вони мають на увазі: у них немає методу перетворити потік журналів у причинно-наслідковий ланцюг. Шум — це інформація, яку ви не індексуєте.

Правило «першої поганої події»

Більшість інцидентів мають одну з цих форм:

  • Одна жорстка відмова: наприклад, помилка дискового вводу/виводу → файлову систему перемонтували в read-only → база даних панікує → помилки API.
  • Одна повільна відмова: наприклад, сплеск затримок → черга запитів зростає → пул потоків насичується → таймаути по всій системі.
  • Одна неправильна конфігурація: наприклад, пропущена ротація сертифіката → TLS-шейкхенки не проходять → перевірки здоров’я падають → автоскейлер «гонить» ресурси.
  • Одна «нічого не змінилось» брехня: залежність змінилась поза вашим контролем (час, DNS, upstream-деплой, хмарна контрольна площина).

Найбільш ефективний ваш хід — ідентифікувати найраннішу часову мітку, коли реальність відхилилась від норми, потім йти вперед і спостерігати, як розширюється область впливу. Ідіть назад теж, але назад здебільшого потрібен, щоб відкидати зайві гіпотези.

Журнали мають сенс лише якщо синхронізувати годинники

Якщо годинники у вашому флоті відстають або йдуть вперед, кореляція — це вигадка. Виправте NTP/chrony перед тим, як ускладнювати парсинг. Час — це первинний ключ операцій.

Одна парафразована ідея, яку варто прикріпити до монітора (і ви зрозумієте чому в плані дій): paraphrased idea — John Allspaw, про цінність доказового реагування на інциденти та навчання на реальній поведінці системи.

Цікаві факти та історія, що роблять сучасні журнали дивними

  • Syslog старший за більшість вашого стеку. Він був розроблений у 1980-х для простих текстових повідомлень, а не для JSON-пейлоадів і trace ID.
  • RFC 3164 syslog-мітки часу не містять року. Ось чому деякі парсери вгадують і іноді помиляються близько Нового року.
  • journal systemd зберігає структуровані поля. Можна фільтрувати по _SYSTEMD_UNIT, PID, _COMM та ін. без глобального регулярного виразу.
  • Кільце ядра не є надійним архівом. dmesg — це круговий буфер; під навантаженням найважливіші повідомлення можуть бути перезаписані першими.
  • Рівні логів — це соціальна домовленість. Багато додатків трактують «ERROR» як «мені потрібна увага», а «WARN» — як «я теж хочу уваги, але зі стидом менше».
  • rsyslog та syslog-ng створювалися для пропускної здатності. Вони можуть скидати повідомлення під навантаженням, якщо неправильно налаштовані або якщо дисковий ввід/вивід зависає; «відсутні логи» можуть бути симптомом.
  • Сповіщення поштою існують довше за вебхуки. SMTP нудний, повсюдний і досі один із найнадійніших останніх каналів повідомлення, коли API вогнем палає.
  • journald rate limiting — двосічний меч. Він може врятувати диск під час «спамового» збою, але також може приховати частоту патерну помилок.
  • Збої сховища часто шепочуть першими. Помилки UDMA CRC, скидання лінків або ZFS checksum errors можуть з’явитися задовго до прямого «I/O error».

І так, ваші логи міститимуть принаймні один рядок, який технічно правильний, але емоційно марний.

Жарт 1: Якщо ваш план реагування на інциденти — «tail логів і відчувати емоції», вітаю — ви винайшли артізанський дебаг.

Швидкий план діагностики: перша / друга / третя перевірки

Ось послідовність, якою я користуюсь, коли ще не знаю, що трапилось. Вона оптимізована на «швидко знайти вузьке місце», а не на побудову ідеальної наративи. Ідеальну наративу можна робити пізніше, під час постмортему, коли система стабільна і кава легальна.

Перше: встановіть вікно інциденту та область ураження

  1. Виберіть часовий проміжок. Почніть з «коли користувачі помітили» і розширте на 10–30 хвилин раніше.
  2. Визначте уражені хости та юніти. Це один вузол, одна зона доступності, один сервіс чи все одразу?
  3. Шукайте першу жорстку помилку. Kernel, storage, OOM, падіння сервісу, TLS-збій.

Друге: перевірте «велику трійку» ресурсних обмежень

  1. Насичення CPU або троттлінг? Шукайте сплески load, scheduler latency, cgroup throttling.
  2. Тиск пам’яті? OOM kills, свопінг, reclaim-шторм.
  3. I/O та сховище? Затримки диска, помилки файлової системи, скидання контролера, події ZFS, queue depth.

Третє: підтвердіть причинність кореляцією

  1. Скорелюйте часові мітки. Чи йде помилка додатку після події ядра/сховища?
  2. Знайдіть «першу появу». Найраніше повідомлення в патерні часто є тригером.
  3. Підтвердіть другим сигналом. Метрики, якщо є; якщо ні — інші логи (auth, kernel, storage).

Коли застрягли

  • Перейдіть від grep до фільтрації за джерелом: unit, PID, виконуваний файл, container ID.
  • Зменшіть область: один хост, одна хвилина, один unit.
  • Перевіряйте kernel і шари storage, навіть якщо «ви знаєте», що це баг додатку. Ви насправді не знаєте.

Практичні завдання (команди, виводи, рішення)

Це реальні завдання, які ви можете виконати на Linux-машині з systemd. Кожне містить: команду, що означає її вивід, і яке рішення прийняти далі. Мета — перетворити «суп з логів» у послідовність рішень.

Завдання 1: Підтвердити правильність годинника (бо кореляція залежить від цього)

cr0x@server:~$ timedatectl
               Local time: Tue 2026-02-05 02:21:18 UTC
           Universal time: Tue 2026-02-05 02:21:18 UTC
                 RTC time: Tue 2026-02-05 02:21:18
                Time zone: Etc/UTC (UTC, +0000)
System clock synchronized: yes
              NTP service: active
          RTC in local TZ: no

Значення: Ви хочете бачити «System clock synchronized: yes» і активний NTP.

Рішення: Якщо годинники не синхронізовані, спочатку виправте час (chrony/systemd-timesyncd), інакше кореляція логів бреше.

Завдання 2: Швидко обмежити вікно інциденту

cr0x@server:~$ journalctl --since "2026-02-05 01:45:00" --until "2026-02-05 02:15:00" -p err..alert --no-pager
Feb 05 01:52:11 server kernel: blk_update_request: I/O error, dev sdb, sector 1946152832 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
Feb 05 01:52:11 server kernel: Buffer I/O error on dev sdb1, logical block 243269104, async page read
Feb 05 01:52:12 server systemd[1]: postgresql.service: Main process exited, code=killed, status=9/KILL
Feb 05 01:52:12 server systemd[1]: postgresql.service: Failed with result 'signal'.

Значення: Показано лише події високої серйозності. Помилка I/O ядра з’являється перед тим, як PostgreSQL помер. Порядок важливий.

Рішення: Розглядайте сховище як підозріле негайно; не гайте 45 хвилин на «налаштування Postgres», поки диск повертає I/O помилки.

Завдання 3: Визначити першу появу патерну

cr0x@server:~$ journalctl --since "2026-02-05 01:00:00" | grep -m1 -E "I/O error, dev sdb|Buffer I/O error"
Feb 05 01:52:11 server kernel: blk_update_request: I/O error, dev sdb, sector 1946152832 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0

Значення: -m1 зупиняє пошук на першому збігу, даючи найраніше відоме появлення в потоці.

Рішення: Використайте ту часову мітку як точку опори. Все, що після — потенційно наслідок.

Завдання 4: Фільтрувати журнали по systemd unit замість grep по всьому

cr0x@server:~$ journalctl -u postgresql.service --since "2026-02-05 01:45:00" --no-pager | tail -n 12
Feb 05 01:52:10 server postgres[21455]: LOG:  could not read block 243269104 in file "base/16384/2619": read only 0 of 8192 bytes
Feb 05 01:52:10 server postgres[21455]: LOG:  unexpected pageaddr 0/0 in log segment 0000000100000000000000A3, offset 0
Feb 05 01:52:11 server postgres[21455]: PANIC:  could not read from log segment 0000000100000000000000A3 at offset 0: read only 0 of 8192 bytes
Feb 05 01:52:12 server systemd[1]: postgresql.service: Main process exited, code=killed, status=9/KILL
Feb 05 01:52:12 server systemd[1]: postgresql.service: Failed with result 'signal'.

Значення: База даних повідомляє про короткі читання. Це не питання конфігурації; це або сховище, або ядро.

Рішення: Перестаньте припускати «баг бази даних». Ескалюйте розслідування на storage; розгляньте фейловер.

Завдання 5: Перевірити OOM kills (мовчазний вбивця)

cr0x@server:~$ journalctl -k --since "2026-02-05 01:45:00" | grep -E "Out of memory|oom-kill|Killed process" | tail -n 5
Feb 05 01:47:03 server kernel: oom-kill:constraint=CONSTRAINT_NONE,nodemask=(null),cpuset=/,mems_allowed=0,global_oom,task_memcg=/system.slice/api.service,task=java,pid=18802,uid=1001
Feb 05 01:47:03 server kernel: Killed process 18802 (java) total-vm:7421860kB, anon-rss:4823112kB, file-rss:0kB, shmem-rss:0kB, UID:1001 pgtables:12544kB oom_score_adj:0

Значення: Ядро вбило процес через тиск пам’яті, і воно вказує cgroup (/system.slice/api.service).

Рішення: Якщо OOM співпадає з початком інциденту, вважайте тиск пам’яті тригером. Якщо він з’явився пізніше — можливо наслідок повторних спроб і росту черг.

Завдання 6: Перевірити rate limiting journald (бо відсутні логи — проблема)

cr0x@server:~$ journalctl -u systemd-journald --since "2026-02-05 01:45:00" --no-pager | tail -n 8
Feb 05 01:51:58 server systemd-journald[412]: Suppressed 1529 messages from postgresql.service
Feb 05 01:52:01 server systemd-journald[412]: Suppressed 941 messages from kernel

Значення: Ви втрачаєте деталізацію в найгарячішій частині інциденту. Патерн ще має значення, але підрахунки й послідовності можуть бути неповними.

Рішення: Якщо suppression велика, збирайте інші докази (kernel counters, інструменти storage). Розгляньте регулювання rate limits після інциденту, а не під час.

Завдання 7: Впізнати проблеми лінку/сховища в dmesg/journal

cr0x@server:~$ dmesg -T | egrep -i "ata[0-9]|nvme|reset|link is down|I/O error|blk_update_request" | tail -n 12
[Tue Feb  5 01:52:10 2026] ata2.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[Tue Feb  5 01:52:10 2026] ata2.00: failed command: READ FPDMA QUEUED
[Tue Feb  5 01:52:11 2026] blk_update_request: I/O error, dev sdb, sector 1946152832 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
[Tue Feb  5 01:52:11 2026] ata2: hard resetting link
[Tue Feb  5 01:52:12 2026] ata2: SATA link up 6.0 Gbps (SStatus 133 SControl 300)

Значення: Скидання лінку + невдалі читання — класична територія «диск, кабель, контролер або backplane».

Рішення: Плануйте заміну апаратного забезпечення або міграцію. Якщо це VM із віртуальними дисками — розглядайте нестабільність underlying storage і залучайте команду провайдера/платформи.

Завдання 8: Підтвердити сигнали здоров’я файлової системи

cr0x@server:~$ journalctl -k --since "2026-02-05 01:45:00" | egrep -i "EXT4-fs error|XFS.*corruption|Remounting filesystem read-only|I/O error" | tail -n 10
Feb 05 01:52:11 server kernel: EXT4-fs error (device sdb1): ext4_find_entry:1456: inode #131104: comm postgres: reading directory lblock 0
Feb 05 01:52:11 server kernel: Aborting journal on device sdb1-8.
Feb 05 01:52:11 server kernel: EXT4-fs (sdb1): Remounting filesystem read-only

Значення: Файлова система перемонтована в режим read-only. Додатки відтепер будуть падати дивними способами.

Рішення: Перестаньте «перезапускати сервіси». Потрібен фейловер, перемонтування або ремонт. Рестарти додають шуму і можуть погіршити корупцію.

Завдання 9: Якщо ви використовуєте ZFS, перевірте події та помилки pool

cr0x@server:~$ sudo zpool status -x
  pool: tank
 state: DEGRADED
status: One or more devices has experienced an error resulting in data corruption.
action: Replace the device using 'zpool replace'.
  scan: scrub repaired 0B in 0 days 00:12:44 with 3 errors on Tue Feb  5 01:55:21 2026
config:

        NAME        STATE     READ WRITE CKSUM
        tank        DEGRADED     0     0     0
          mirror-0  DEGRADED     0     0     0
            sdb     FAULTED      5     0     3  too many errors
            sdc     ONLINE       0     0     0

errors: Permanent errors have been detected in the following files:
/tank/pg/wal/0000000100000000000000A3

Значення: Це не «можливо». ZFS каже, що пристрій faulted і може назвати пошкоджені файли.

Рішення: Замініть диск, відновіть постраждалі дані з репліки/резервної копії та вважайте помилки застосунку як наслідок, поки не доведено інше.

Завдання 10: Подивіться, які сервіси флапнули (шторм рестартів створює фейкові кореневі причини)

cr0x@server:~$ systemctl list-units --type=service --state=failed
  UNIT                 LOAD   ACTIVE SUB    DESCRIPTION
  postgresql.service    loaded failed failed PostgreSQL RDBMS
  api.service           loaded failed failed Example API

LOAD   = Reflects whether the unit definition was properly loaded.
ACTIVE = The high-level unit activation state.
SUB    = The low-level unit activation state.

Значення: Швидкий інвентар «що видно зламаним». Це не пояснює чому.

Рішення: Використайте це для обмеження blast radius, потім перевірте логи кожного unit навколо найраннішої часової мітки.

Завдання 11: Витягнути структуровані поля з journald (перестаньте робити regex, коли можна фільтрувати)

cr0x@server:~$ journalctl -u api.service --since "2026-02-05 01:45:00" -o json | head -n 3
{"_SYSTEMD_UNIT":"api.service","PRIORITY":"3","MESSAGE":"DB connection failed: timeout","_PID":"18890","_COMM":"java","__REALTIME_TIMESTAMP":"1738720565000000"}
{"_SYSTEMD_UNIT":"api.service","PRIORITY":"3","MESSAGE":"DB connection failed: timeout","_PID":"18890","_COMM":"java","__REALTIME_TIMESTAMP":"1738720566000000"}
{"_SYSTEMD_UNIT":"api.service","PRIORITY":"4","MESSAGE":"Retrying in 500ms","_PID":"18890","_COMM":"java","__REALTIME_TIMESTAMP":"1738720566000000"}

Значення: Можна програмно парсити поля як unit, PID, priority, timestamp. Це те, як будуються надійні оповіщення.

Рішення: Якщо ви пишете автоматизацію — віддавайте перевагу JSON-виводу. Текст для людей; структуровані поля — для машин.

Завдання 12: Порахувати сплески помилок, щоб зрозуміти, чи це шторм

cr0x@server:~$ journalctl -u api.service --since "2026-02-05 01:45:00" --until "2026-02-05 02:00:00" -p err --no-pager | wc -l
842

Значення: 842 повідомлення рівня error за 15 хвилин — це не «пара збоїв». Це системна проблема або агресивний цикл повторів.

Рішення: Якщо лічба велика, зосередьтесь на виявленні upstream-залежності, яка падає, і розгляньте зменшення повторів або увімкнення circuit breakers.

Завдання 13: Кореляція між хостами швидко і брудно (коли бракує централізованого логування)

cr0x@server:~$ for h in app01 app02 db01; do echo "== $h =="; ssh $h "journalctl --since '2026-02-05 01:50:00' --until '2026-02-05 01:55:00' -p err --no-pager | head -n 3"; done
== app01 ==
Feb 05 01:52:13 app01 api[18890]: DB connection failed: timeout
Feb 05 01:52:14 app01 api[18890]: DB connection failed: timeout
Feb 05 01:52:15 app01 api[18890]: DB connection failed: timeout
== app02 ==
Feb 05 01:52:13 app02 api[19011]: DB connection failed: timeout
Feb 05 01:52:14 app02 api[19011]: DB connection failed: timeout
Feb 05 01:52:15 app02 api[19011]: DB connection failed: timeout
== db01 ==
Feb 05 01:52:11 db01 kernel: blk_update_request: I/O error, dev sdb, sector 1946152832 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
Feb 05 01:52:11 db01 kernel: EXT4-fs (sdb1): Remounting filesystem read-only
Feb 05 01:52:12 db01 systemd[1]: postgresql.service: Main process exited, code=killed, status=9/KILL

Значення: Ноди додатків показують таймаути; DB-нода показує помилки storage. Ось ваш ланцюжок із часовими мітками.

Рішення: Перестаньте дебажити аплікації. Ініціюйте фейловер/відновлення БД, а потім виправляйте нижній шар storage.

Завдання 14: Витягти «реальний рядок помилки» з контекстом (10 рядків навколо нього)

cr0x@server:~$ journalctl --since "2026-02-05 01:45:00" --no-pager | grep -n -E "Remounting filesystem read-only|blk_update_request: I/O error" | head -n 1
1823:Feb 05 01:52:11 server kernel: EXT4-fs (sdb1): Remounting filesystem read-only
cr0x@server:~$ journalctl --since "2026-02-05 01:45:00" --no-pager | sed -n '1813,1833p'
Feb 05 01:52:10 server kernel: ata2.00: failed command: READ FPDMA QUEUED
Feb 05 01:52:11 server kernel: blk_update_request: I/O error, dev sdb, sector 1946152832 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 0
Feb 05 01:52:11 server kernel: Buffer I/O error on dev sdb1, logical block 243269104, async page read
Feb 05 01:52:11 server kernel: EXT4-fs error (device sdb1): ext4_find_entry:1456: inode #131104: comm postgres: reading directory lblock 0
Feb 05 01:52:11 server kernel: Aborting journal on device sdb1-8.
Feb 05 01:52:11 server kernel: EXT4-fs (sdb1): Remounting filesystem read-only
Feb 05 01:52:12 server systemd[1]: postgresql.service: Main process exited, code=killed, status=9/KILL
Feb 05 01:52:13 server api[18890]: DB connection failed: timeout

Значення: Контекст перетворює один страшний рядок на причинно-наслідкову послідовність: ATA read failure → block I/O error → abort журналу файлової системи → remount read-only → база помирає → таймаути аплікації.

Рішення: Це ваша опорна хронологія інциденту. Використайте її для дій (фейловера) та пізнішого чистого постмортему.

Завдання 15: Коли «реальна помилка» — TLS/сертифікати, знайдіть її один раз, а не 5000 разів

cr0x@server:~$ journalctl -u nginx.service --since "2026-02-05 00:00:00" --no-pager | grep -m1 -E "certificate|SSL_do_handshake|PEM_read_bio"
Feb 05 01:03:44 server nginx[901]: [emerg] SSL_CTX_use_PrivateKey_file("/etc/nginx/tls/site.key") failed (SSL: error:0B080074:x509 certificate routines:X509_check_private_key:key values mismatch)

Значення: Один рядок пояснює відмову: невідповідність ключ/сертифікат. Все інше — клієнти, які не можуть з’єднатися.

Рішення: Виправте пару сертифікат/ключ, перезавантажте та додайте перевірку перед деплоєм, щоб це не повторилось.

Завдання 16: Виявити «оптимізаційні» відмови як агресивне обертання логів або заповнення tmpfs

cr0x@server:~$ journalctl --since "2026-02-05 01:00:00" -p warning --no-pager | grep -E "No space left on device|failed to write|ENOSPC" | head -n 5
Feb 05 01:11:02 server systemd-journald[412]: Failed to write entry (24 items, 882 bytes), ignoring: No space left on device
Feb 05 01:11:03 server rsyslogd[777]: action 'action-0-builtin:omfile' suspended (module 'builtin:omfile'), retry 0. There is no space left on device.

Значення: Система логування не може записувати. Ви втрачаєте докази під час інциденту.

Рішення: Звільніть місце негайно; потім перегляньте, де зберігаються логи, політику ротації і чи не шкодять зміни «збереження диска» спостережуваності.

Три корпоративні міні-історії з фронту журналів

Міні-історія 1: Інцидент через хибне припущення

Компанія була в середині міграції: новий Kubernetes-кластер, новий service mesh, все нове. Клієнтоорієнтований API почав повертати 502 помилок випадково. Інженер on-call зробив те, що більшість з нас роблять під тиском: він шукав у логах «error» і побачив бурю «upstream reset» повідомлень у проксі.

Припущення сформувалось миттєво: «баг service mesh». Було зібрано war room. Люди підправляли таймаути проксі, перезапускали sidecar, змінювали feature flags. Рівень помилок трохи змінювався, що відчувалося як прогрес, але фактично було випадковою варіацією, прийнятою за контроль.

Зрештою хтось перевірив kernel-логи на одній ноді. Не логи додатку, не проксі-логи. Нода повідомляла про NIC link flaps і TCP retransmits. Проксі був невинний; він просто перший компонент, який чесно поскаржився. Коли команда скорелювала часові мітки, кожен upstream reset вирівнювався з циклом link down/up.

Корінь проблеми був банальний: порт на top-of-rack свічі мав невірну швидкість/дуплекс після планового обслуговування. «Інцидент mesh» виявився мережею в маскарадній формі проксі.

Урок не в «завжди звинувачуй мережу». Урок: не дозволяйте першому правдоподібному повідомленню стати вашою версією root cause. Логи говорять, що компонент спостерігав, а не те, що спричинило поломку.

Міні-історія 2: Оптимізація, що зіграла злий жарт

Платформна команда намагалася скоротити використання диску на флоті баз даних. Хтось помітив, що journald споживає несподівано багато місця. Виправлення виглядало чисто: агресивно обмежити розмір журналу і увімкнути жорсткіший rate limiting. Менше диску, менше записів, щасливі SSD. Усі люблять перемогу.

Через два тижні одна нода зазнала періодичних латентних сплесків сховища. PostgreSQL почав логувати повільні fsync і затримки запису WAL. На рівні аплікації з’явились таймаути. On-call намагався скласти хронологію, але kernel-повідомлення навколо сплеску відсутні. Journald подав багато suppress, а обмежений журнал уже відкотив ранні попередження.

Без ранніх доказів команда зосередилась на конфігурації бази даних. Вони налаштували checkpoints, змінили WAL-параметри, підкоригували kernel dirty ratios. Деякі зміни покращили стабільний стан і дали відчуття, що «інженеримо». Але сплески залишились.

Пізніше під час вікна обслуговування хтось запустив scrub на пулі сховища і знайшов що зростають checksum errors. Диск повільно деградував, і система попереджала про це. Ці попередження були першими, що були «відрізані», бо сталися до інциденту.

Оптимізація не спричинила апаратний збій. Вона позбавила команду єдиного дешевого раннього сигналу, який міг би скоротити інцидент. Заощадження диску — ок; збереження диску ціною форензичних слідів — ні.

Міні-історія 3: Нудна, але правильна практика, що врятувала день

Сервіс платежів мав звичку, яку ніхто не святкував: кожен деплой вимагав невеликий «чекліст sanity журналу подій». Не великий аудит безпеки. Просто нудні перевірки — синхронізація часу, місце на диску, здоров’я journald і простий end-to-end транзакційний тест у канарі.

Одного ранку канар відпав. Логи показали помилки TLS handshake. Інженер на чергуванні не робив сліпий grep; він відфільтрував по unit і шукав першу помилку, пов’язану з сертифікатом. Це було відразу: сервіс загрузив новий ланцюжок сертифікатів, але відсутній був проміжний сертифікат. Сервіс стартував, але відмовляв клієнтам, які вимагали повний ланцюжок.

Виправлення — один рядок: встановити проміжний і перезавантажити. Ніякого інциденту, ніякого впливу на клієнтів. Чекліст зловив це ще до того, як воно вийшло назовні. Команда була трохи роздратована, що «нічого не сталося», і це правильна емоційна реакція на добре спроектований процес.

Та практика не здавалася інноваційною. Але була. Більшість відмов запобігаються речами, що виглядають як паперова робота — до моменту, коли вона знадобиться.

Надішліть собі електронний лист: виробничий канал сповіщень із журналів

Централізоване логування чудове. Але іноді його нема. Іноді саме воно падає. Email, попри вади, є стійким, має мало залежностей і доступний майже звідусіль. «Надішліть собі листа» — не примітив; це прагматично.

Хитрість — уникнути двох режимів відмов:

  • Спам оповіщень: ви ігноруєте їх і пропускаєте єдине важливе повідомлення.
  • Мовчання оповіщень: скрипт падає, SMTP падає, DNS падає або journald подавлює події і ви ніколи не дізнаєтесь.

Принципи дизайну для лог→email оповіщень

  1. Сповіщуйте про тригери, а не симптоми. «EXT4 remounted read-only» кращий за «API timeout» у сто разів.
  2. Агресивно дедуплікуйте. Email — не часовий ряд метрик.
  3. Включайте контекст. Надсилайте перший рядок помилки плюс невелике вікно рядків навколо.
  4. Зробіть тестованим. Ви повинні мати змогу запустити скрипт і отримати один детерміністичний вихід.
  5. Падайте голосно. Якщо pipeline оповіщень не може надіслати — залогуйте цей провал туди, де ви його побачите.

Проста, надійна реалізація: systemd timer + journalctl cursor

Ми використаємо курсор journald, щоб запам’ятовувати, де зупинилися. Це запобігає «повторній розсилці світу» і надійніше, ніж вгадування часових вікон.

1) Створіть скрипт оповіщення

Цей скрипт шукає події високої серйозності та кілька специфічних шаблонів тригерів (storage, OOM, remount read-only, несумісність сертифікатів). Він надсилає один лист за прогін, дедуплікований, з «топовою» знахідкою.

cr0x@server:~$ sudo tee /usr/local/sbin/journal-alert-email.sh >/dev/null <<'EOF'
#!/usr/bin/env bash
set -euo pipefail

STATE_DIR="/var/lib/journal-alert"
CURSOR_FILE="$STATE_DIR/cursor"
HOST="$(hostname -f 2>/dev/null || hostname)"
TO_ADDR="oncall@example.com"
FROM_ADDR="journal-alert@$HOST"
SUBJECT_PREFIX="[journal-alert]"
TMP="$(mktemp)"
trap 'rm -f "$TMP"' EXIT

mkdir -p "$STATE_DIR"
chmod 700 "$STATE_DIR"

# Pull new high-priority logs since last cursor.
# We intentionally include kernel + system units; customize for your environment.
if [[ -f "$CURSOR_FILE" ]]; then
  journalctl --after-cursor "$(cat "$CURSOR_FILE")" -p err..alert -o short-iso --no-pager > "$TMP" || true
else
  journalctl --since "10 minutes ago" -p err..alert -o short-iso --no-pager > "$TMP" || true
fi

# Update cursor regardless; prevents loops if one bad message repeats.
journalctl -n 1 -o json --no-pager | sed -n 's/.*"__CURSOR":"\([^"]*\)".*/\1/p' > "$CURSOR_FILE" || true
chmod 600 "$CURSOR_FILE"

# If no new events, exit quietly.
if [[ ! -s "$TMP" ]]; then
  exit 0
fi

# Prefer trigger patterns; fall back to first error line.
TRIGGER_LINE="$(grep -m1 -E \
  'Remounting filesystem read-only|blk_update_request: I/O error|Buffer I/O error|oom-kill|Killed process|X509_check_private_key|SSL_CTX_use_PrivateKey_file|No space left on device|Permanent errors have been detected' \
  "$TMP" || true)"

if [[ -z "$TRIGGER_LINE" ]]; then
  TRIGGER_LINE="$(head -n 1 "$TMP")"
fi

# Add some context around the trigger if present in TMP.
CONTEXT="$(awk -v needle="$TRIGGER_LINE" '
  BEGIN{found=0}
  $0==needle{found=1; start=NR-5; end=NR+10}
  {lines[NR]=$0}
  END{
    if(found){
      for(i=(start<1?1:start); i<=end; i++) if(i in lines) print lines[i]
    } else {
      for(i=1;i<=20;i++) if(i in lines) print lines[i]
    }
  }' "$TMP")"

SUBJECT="$SUBJECT_PREFIX $HOST $(echo "$TRIGGER_LINE" | cut -c1-120)"
BODY=$(cat <<EOT
Host: $HOST
Time: $(date -Is)
Trigger:
$TRIGGER_LINE

Context:
$CONTEXT
EOT
)

# Send email. Requires a local MTA or msmtp configured.
printf "%s\n" "$BODY" | /usr/bin/mail -s "$SUBJECT" -r "$FROM_ADDR" "$TO_ADDR"
EOF
sudo chmod 750 /usr/local/sbin/journal-alert-email.sh

Що це означає: Це використовує journald як джерело істини і курсор для стану. Надсилається одне повідомлення за прогін, що природно обмежує частоту.

Рішення: Якщо ви не можете гарантувати локальний MTA, використайте msmtp або ретранслятор. Не покладайтеся на «чийсь ноутбук» для доставки оповіщень.

2) Налаштуйте мінімальний поштовий відправник (приклад: msmtp)

На багатьох системах mail працюватиме з локальним MTA. Якщо його немає — msmtp поширений вибір. Нижче приклад конфігу; адаптуйте під своє середовище.

cr0x@server:~$ sudo tee /etc/msmtprc >/dev/null <<'EOF'
defaults
auth           on
tls            on
tls_trust_file /etc/ssl/certs/ca-certificates.crt
logfile        /var/log/msmtp.log

account        relay
host           smtp.relay.local
port           587
from           journal-alert@server.example
user           journal-alert@server.example
passwordeval   "cat /etc/msmtp-password"

account default : relay
EOF
sudo chmod 600 /etc/msmtprc

Що це означає: Креденціали зберігаються поза скриптом. Мейлер логгує у файл, який можна аудіювати.

Рішення: Якщо не можете належно захистити креденціали — не викладайте їх. Використовуйте локальний ретранслятор з IP-автентифікацією або внутрішній SMTP-сервіс.

3) Створіть systemd service + timer

cr0x@server:~$ sudo tee /etc/systemd/system/journal-alert-email.service >/dev/null <<'EOF'
[Unit]
Description=Send email alerts for high-severity journal events
After=network-online.target
Wants=network-online.target

[Service]
Type=oneshot
ExecStart=/usr/local/sbin/journal-alert-email.sh
Nice=10
IOSchedulingClass=best-effort
IOSchedulingPriority=7
EOF
cr0x@server:~$ sudo tee /etc/systemd/system/journal-alert-email.timer >/dev/null <<'EOF'
[Unit]
Description=Run journal email alert script every minute

[Timer]
OnBootSec=2min
OnUnitActiveSec=1min
AccuracySec=10s
Persistent=true

[Install]
WantedBy=timers.target
EOF
sudo systemctl daemon-reload
sudo systemctl enable --now journal-alert-email.timer

Що це означає: Кожну хвилину таймер запускає скрипт один раз. Якщо хост був вимкнений, Persistent=true виконає пропущені інтервали при завантаженні (корисно для виявлення ранніх проблем при старті).

Рішення: Якщо хвилює обсяг листів — підвищте інтервал до 2–5 хвилин і дедуплікуйте всередині скрипту. Не запускайте кожні 5 секунд — ви швидко почнете ненавидіти власну пошту.

4) Протестуйте конвеєр від початку до кінця

cr0x@server:~$ sudo systemctl start journal-alert-email.service
cr0x@server:~$ sudo systemctl status journal-alert-email.service --no-pager
● journal-alert-email.service - Send email alerts for high-severity journal events
     Loaded: loaded (/etc/systemd/system/journal-alert-email.service; static)
     Active: inactive (dead) since Tue 2026-02-05 02:23:20 UTC; 2s ago
    Process: 22901 ExecStart=/usr/local/sbin/journal-alert-email.sh (code=exited, status=0/SUCCESS)

Значення: status=0/SUCCESS означає, що скрипт виконався. Він міг нічого не надіслати, якщо нових помилок не було.

Рішення: Якщо потрібен тестовий лист — тимчасово знизьте поріг або згенеруйте контрольований рядок помилки в безпечному unit/середовищі.

Жарт 2: Email-оповіщення — як датчики диму: ви помічаєте їх лише коли вони дратують, і саме тоді вони виконують свою роботу.

Чеклісти / покроковий план

Чекліст: знайти справжню помилку в журналах за 10 хвилин

  1. Встановіть вікно: визначте since і until; розширте раніше, якщо потрібно.
  2. Витягніть події високої серйозності спочатку: journalctl -p err..alert для вікна.
  3. Проскануйте на тригери: kernel I/O, remount read-only, OOM, падіння сервісу, помилки TLS/сертифікатів, ENOSPC.
  4. Знайдіть найраніший рядок-тригер: використайте grep -m1 або курсор-сканування.
  5. Додайте контекст: захопіть 10 рядків перед/після або фільтруйте по unit.
  6. Скорелюйте по шарах: логи аплікації + systemd + kernel.
  7. Прийміть рішення: фейловер, rollback, рестарт (рідко) або ескалація на hardware/network/platform.
  8. Збережіть докази: скопіюйте релевантні зрізи журналу і kernel-логи перед перезавантаженням або ротацією.

Чекліст: безпечне для продукції лог-оповіщення поштою

  1. Виберіть шаблони тригерів, за які ви дійсно готові прокинутись.
  2. Реалізуйте стан курсора, щоб уникати дублікатів і проблем з дрейфом часу.
  3. Дедуплікуйте всередині прогона (надсилайте один лист з топ-тригером + контекстом).
  4. Використовуйте надійний поштовий шлях (локальний ретранслятор або авторизований SMTP).
  5. Запустіть із systemd timer і моніторьте помилки самого сервісу оповіщень.
  6. Тестуйте щоквартально (так, дійсно): оповіщувальні конвеєри тихо відмирають.

Чекліст: триаж, орієнтований на сховище (бо сховище «бреше», будучи повільним)

  1. Шукайте в kernel-логах link resets, I/O errors, remounts.
  2. Перевірте RAID/ZFS/MD події, якщо застосовно.
  3. Підтвердіть, що «помилка аплікації» почалась після попереджень про сховище.
  4. Зробіть фейловер або зменшіть навантаження перед ремонтами.
  5. Після стабільності — запускайте scrubs/checks і замінюйте проблемні компоненти.

Поширені помилки: симптом → корінь → виправлення

1) «Усе таймаутить»

Симптом: логи аплікації повні таймаутів; reverse proxy показує upstream errors.

Корінь: нода бази даних перемонтована в read-only після I/O помилок; аплікація не винна.

Виправлення: перевірте kernel + filesystem логи, зробіть фейловер бази, замініть диск/кабель/контролер; припиніть перезапускати аплікаційні сервіси.

2) «Сервіс постійно рестартиться — мусить бути crash loop»

Симптом: systemd показує повторні рестарти; логи аплікації обриваються.

Корінь: kernel OOM killer вбиває процес (часто через некероване зростання пам’яті, сплески трафіку або межі cgroup).

Виправлення: підтвердіть OOM у kernel-логах, збільште пам’ять або виправте витік, налаштуйте cgroup limits, додайте backpressure/circuit breakers.

3) «Немає помилок у логах, тому хост не винен»

Симптом: ви не бачите очікуваних kernel/storage повідомлень під час інциденту.

Корінь: journald suppression, агресивна ротація або заповнений диск завадили запису логів.

Виправлення: перевірте journald на suppression і ENOSPC, збільште retention, забезпечте запас місця на розділі для логів і оповіщайте про «нездоров’я» пайплайну логування.

4) «Ми вирішили, збільшивши таймаути»

Симптом: підняття таймаутів тимчасово зменшило рівень помилок.

Корінь: повільна залежність (латентність storage, проблеми DNS, перевантажена БД) була тригером; таймаути лише перенесли проблему.

Виправлення: знайдіть найраніший latency/IO тригер, зменшіть навантаження або зробіть фейловер; тонкіть таймаути лише після стабілізації, щоб не спричинити retry-шторм.

5) «Ротація сертифікатів автоматизована, отже TLS не може бути проблемою»

Симптом: раптові handshake failures після деплою; клієнти повідомляють про помилки ланцюжка сертифікатів.

Корінь: невідповідність ключ/сертифікат, відсутній проміжний, неправильні права файлу або процес не перезавантажився.

Виправлення: шукайте перший TLS/key error рядок, перевіряйте пару сертифікат/ключ у CI, забезпечте перевірки перезавантаження і оповіщення про наближення закінчення терміну дії.

6) «Це знову мережа» (кожного разу)

Симптом: випадкові скидання, ретрансміти, рандомні збої.

Корінь: іноді мережа, так. Інколи — завантаження CPU, яке викликає затримки ACK, дискові стаги, що «заморожують» процеси, або вичерпання conntrack.

Виправлення: підтверджуйте kernel-логами та сигналами навантаження хоста. Не робіть козла відпущення. Доведіть.

7) «Просто зробимо grep по ERROR»

Симптом: нескінченні збіги, ніякої ясності, неправильний фокус.

Корінь: неправильне використання рівнів логування і брак структурованої фільтрації (unit/PID/поля).

Виправлення: фільтруйте за unit і priority, потім шукайте тригерні патерни; використовуйте JSON-поля для автоматизації.

FAQ

1) Що таке «справжня помилка» в журналі подій?

Це найраніша високо-сигнальна подія, яка пояснює подальші відмови: перша I/O помилка, перший OOM kill, перша невідповідність TLS-ключа, перший «remount read-only». Не 50-й таймаут.

2) Чому не просто відправляти все в лог-платформу і шукати там?

Вам слід це робити, коли можна. Але реагування на інциденти не має залежати від системи, яка може деградувати під час того ж інциденту. Локальні інструменти — ваш рятувальний човен.

3) Чому journalctl -xe здається марним під час інцидентів?

Бо він змішує серйозність, охоплення і час у спосіб, що підходить для «що щойно сталося», але поганий для «що спричинило інцидент». Використовуйте обмежені вікна, пріоритети та фільтри по unit.

4) Як уникнути втоми від оповіщень, коли надсилаю листи собі?

Сповіщуйте про тригери, дедуплікуйте, надсилайте один лист за прогін і тримайте коротку, але специфічну тему. Якщо з листа ви не візьметеся за дію — не надсилайте його.

5) Парсити логи регулярними виразами чи структурованими полями?

Для джерела journald віддавайте перевагу структурованим полям, коли можливо. Використовуйте regex для співпадіння вмісту message, але не будуйте крихку конвеєрну логіку, що залежить лише від точного формулювання.

6) Що робити, якщо система використовує класичні syslog-файли замість journald?

Метод залишається тим самим: обмежте вікно, пріоритетні події, знайдіть перший тригер, додайте контекст і корелюйте по шарах. Команди змінюються (наприклад, grep, awk, zgrep по ротаційних файлах), але рішення — ті самі.

7) Як зрозуміти, чи помилка аплікації — причина чи наслідок?

Перевіряйте порядок і незалежність. Якщо kernel/storage/oom події передують помилкам аплікації — аплікація, ймовірно, downstream. Якщо аплікаційні помилки з’являються самі без змін у kernel-логах — аплікація може бути тригером.

8) Який мінімальний набір шаблонів тригерів варто оповіщувати?

Почніть з: remount filesystem read-only, kernel I/O errors, OOM kills, disk full/ENOSPC, повторні падіння сервісів і помилки завантаження TLS/сертифікатів. Додавайте лише коли доведено, що оповіщення дійсно дієві.

9) А под контейнерів — чи допомагає journald?

Так, якщо логи контейнерів маршрутизовано в journald або якщо systemd управляє runtime контейнера. Якщо використовується інший драйвер логування — збирайте еквівалентні сигнали від runtime і все одно корелюйте з kernel-логами.

10) Скільки зберігати логи на сервері?

Достатньо, щоб включати «ранні попередження», які передують інцидентам: від днів до тижнів, залежно від дискового бюджету. Якщо не можете дозволити ретеншен — не зможете відлагодити наступний повільно-наростаючий збій.

Висновок: що зробити до обіду

Якщо нічого іншого — зробіть ці три речі:

  1. Прийміть правило «першої поганої події». Знайдіть найраніший рядок-тригер і побудуйте причинний ланцюг вперед.
  2. Використовуйте фільтрацію journald як дорослий. Пріоритети, фільтри по unit, структуровані поля. Regex — інструмент, а не стиль життя.
  3. Підключіть невелике email-оповіщення для важливих тригерів. На базі курсора, дедупліковане, з контекстом. Ви подякуєте собі о 02:13.

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

← Попередня
Відновлення ZFS: пул не імпортується? Спокійний та відтворюваний шлях виправлення
Наступна →
Синій екран після встановлення драйвера: відкат із режиму відновлення

Залишити коментар