Аналіз поштових логів: pflogsumm, GoAccess і пошук проблемних патернів доставки
Сирий mail.log на завантаженому сервері — це десятки тисяч рядків шуму. Показуємо, як побудувати двошаровий конвеєр спостереження: pflogsumm як щоденний числовий звіт і GoAccess як візуальний дашборд, і головне — як читати deferral-патерни, щоб відрізнити нешкідливий greylisting від блоку по репутації до того, як він уб'є вашу IP.
EvilMail Team18 липня 2026 р.12 хв читання
Ось чотири рядки з /var/log/mail.log завантаженого mail-хоста. Прочитайте їх і скажіть, у якому з них проблема ваша, а в якому — чужа:
text
postfix/smtp[21440]: A1B2: to=<[email protected]>, relay=mx.corp.com[203.0.113.9]:25, status=sent (250 2.0.0 OK)
postfix/smtp[21441]: C3D4: to=<[email protected]>, relay=mx.example.net[198.51.100.7]:25, status=deferred (host mx.example.net said: 451 4.7.1 Greylisting in action, please come back later)
postfix/smtp[21442]: E5F6: to=<[email protected]>, relay=gmail-smtp-in.l.google.com[142.250.1.27]:25, status=bounced (host gmail-smtp-in.l.google.com said: 550 5.7.26 Unauthenticated email ... SPF/DKIM/DMARC ...)
postfix/smtpd[21443]: NOQUEUE: reject: RCPT from unknown[45.61.х.х]: 554 5.7.1 Service unavailable; Client host [45.61.х.х] blocked using zen.spamhaus.org
Рядок 2 — нешкідливий greylisting: Postfix повторить спробу за налаштований час, і лист піде. Рядок 3 — це вже ваша проблема: Google відбиває пошту, бо не сходиться автентифікація. Рядок 4 — узагалі не про доставку, це вхідне з'єднання, яке Postfix правильно відрубав по RBL. На чотирьох рядках це читається очима. На тисячах — ні, а на temp-mail інфраструктурі evilmail таких рядків десятки тисяч на добу. Тому потрібна агрегація — не «на всяк випадок в архів», а щоденний рентген доставки.
Будуємо дві осі аналізу. pflogsumm відповідає на питання «скільки і які коди» — числовий добовий звіт. GoAccess відповідає на «як це виглядало в часі й хто хости» — візуальний дашборд. Це не конкуренти, а дві гілки одного конвеєра.
Метрики, за якими судимо здоров'я, задаємо одразу: deferred rate, bounce rate, reject rate і топ причин deferral. Усе інше в звіті — контекст навколо цих чотирьох чисел.
pflogsumm: щоденний звіт, який реально читають
Ставиться однією командою, тягне за собою перловий Date::Calc:
bash
apt install pflogsumm # Debian/Ubuntu, на RHEL — з CPAN або пакета postfix-pflogsumm
Базовий прогін по вчорашньому дню:
bash
pflogsumm -d yesterday /var/log/mail.log
Але «голий» звіт — це стіна тексту. Робочий варіант, який я ставлю в cron, виглядає так:
Розберемо прапорці, бо кожен тут не випадковий. --problems-first виносить deferral/bounce/reject нагору — ви бачите проблеми раніше за статистику обсягів. --iso-date-time дає нормальні дати замість перлового формату. -u 10 -h 10 обмежують топи до 10 користувачів і 10 хостів (інакше на busy-сервері секції розповзаються на екрани). --verbose-msg-detail розкриває конкретні тексти помилок у detail-секціях — саме заради них усе й затівається. --zero-fill не приховує години з нульовим трафіком, і це критично для трендів: без нього ніч без пошти просто зникає, і погодинний графік бреше.
Читаємо звіт зверху вниз. Grand Totals — received/delivered/deferred/bounced/rejected, ваш пульс за добу. Per-Hour Traffic Summary — розподіл по годинах, тут видно нічні сплески (частіше атака, ніж легітим). Host/Domain Summary окремо для inbound і outbound. Далі топи: senders by message count/size, recipients by message count. І головне — три detail-секції: message deferral detail, message bounce detail, message reject detail. Тут ви бачите не «5% deferred», а *чому саме* deferred, дослівним текстом віддаленого сервера.
Якщо logrotate уже стиснув учорашній лог, годуйте pflogsumm через zcat:
Зверніть увагу на mail.log.1, а не mail.log. Це головна пастка: якщо logrotate крутить лог опівночі, то о 6:25 «вчорашні» дані вже лежать у .1, а поточний mail.log містить лише сьогоднішній ранок. Візьмете mail.log — отримаєте порожній або куций звіт і будете думати, що сервер учора мовчав.
Друга пастка — компресія. Якщо в logrotate стоїть compress без delaycompress, то .1 вже буде .1.gz, і pflogsumm його не прочитає напряму. Тому у фрагменті для mail.log тримайте delaycompress — вона відкладає стиснення на один цикл, лишаючи .1 у чистому вигляді рівно на ту добу, поки його читає cron:
rotate 30 — тримаємо місяць звітів. Це не про диск, а про тренд: щоб порівняти deferred rate тиждень-до-тижня і побачити повзучу деградацію репутації раніше, ніж вона стане bounce-штормом.
Читання патернів: 4xx проти 5xx, і що за ними стоїть
Це найважливіша частина, і саме її немає в туторіалах рівня «встановіть pflogsumm». Код відповіді — це не помилка, яку треба «полагодити», а діагноз, який треба правильно прочитати. Груба різниця: 4xx — тимчасово, повторимо, 5xx — остаточна відмова. Але всередині кожної групи причини кардинально різні за терміновістю.
Практичні орієнтири по кожному листу дерева:
`451 4.7.1 Greylisting` — отримувач просить прийти пізніше. Postfix сам повторить за налаштованим minimal_backoff_time. Якщо в топі deferral detail — це фон, не інцидент.
`Connection timed out` / `No route to host` — проблема на боці MX отримувача або вашого мережевого шляху. Разово — ігнор; той самий домен третій день — пишіть їм або перевіряйте firewall.
`421 4.7.28 ... unusual rate` (Google) / `S3150` (Microsoft) — це rate-limit, і він прямо каже: ваша IP-репутація просіла, вас притримують. Не «полагодити конфіг», а розбиратися з обсягами і скаргами.
`550 5.7.26 ... SPF/DKIM/DMARC` — Gmail відбиває, бо не сходиться автентифікація. Перевіряйте DKIM-підпис і SPF-запис негайно: кожен такий bounce — це репутаційний мінус.
`554 5.7.1 blocked using zen.spamhaus.org` — ваш IP у блоклісті. Перевірка руками: для IP 203.0.113.10 розвертаємо октети й питаємо dig +short 210.69.22.212.zen.spamhaus.org. Порожня відповідь — чисто; повернулось 127.0.0.x — ви в лісті, ідіть на делістинг.
Головна евристика, яка відрізняє інженера від того, хто просто дивиться в лог: якщо той самий 5xx-домен щодня в топі bounce detail — це ваша проблема, не їхня. Разовий сплеск на невідомий домен — шум. Systematic Gmail-bounce три ранки поспіль — ідіть чинити DKIM.
Окремо — backscatter і словникові атаки. Коли в reject detail раптом сотні NOQUEUE: reject ... 550 5.1.1 User unknown на неіснуючі локальні адреси, це не збій доставки, а перебір адрес. Для temp-mail сервісу як evilmail це фон життя, але сплеск варто помітити: він і IP-репутацію псує, і чергу забиває.
GoAccess: побачити форму потоку
GoAccess створений під web-логи, тож головна робота — привести syslog-формат Postfix до чогось, що він розбере. Битися з кастомним --log-format/--date-format/--time-format під багаторядкову природу Postfix (де один лист — це кілька рядків із різними queue id) — заняття на любителя. Практичніший шлях — препроцес: витягнути awk/grep'ом статус, relay-хост і код у плоский CSV і згодувати GoAccess через stdin.
Тризначний match($0,/.../,arr) із масивом-захопленням — це розширення gawk, тому виклик саме gawk, а не mawk. Живий дашборд із real-time оновленням через WebSocket:
Для WS потрібен відкритий порт або reverse-proxy на nginx (proxy_pass + Upgrade-заголовки). Дивитись у GoAccess варто три речі: розподіл по годинах (нічний сплеск = ймовірна атака), top relay-хости (куди йде найбільше deferred — часто один провайдер) і географію вхідних для temp-mail. Чесна ремарка: GoAccess тут — доповнення «побачити форму», а не заміна pflogsumm. Числа для порогів дає pflogsumm; GoAccess дає очі.
Зведення в один потік і трігери
pflogsumm дає числа — з них робимо пороги. Простий bash-guard, який парсить вивід і б'є на сполох, якщо deferred rate перевищив 5% або з'явився новий RBL-reject:
Куди це масштабується далі: postfix_exporter або grok_exporter → Prometheus → Grafana, і ви отримуєте графіки deferred rate у часі з алертами через Alertmanager. Але не переускладнюйте: для одного-двох mail-хостів зв'язка cron + pflogsumm + GoAccess закриває 90% потреб, і її можна підняти за годину, а не за тиждень.
Чекліст щоденного аудиту логів
deferred rate проти вчора — виріс різко? Дивись причину, не паникуй на 4xx.
Топ-3 deferral reasons — greylisting норм; timeout/no route на одному домені третій день — копай.
Новий 5xx-домен у bounce detail — особливо Gmail/Outlook із SPF/DKIM-текстом.
Сплеск reject — це атака (словник/backscatter) чи легітим? Дивись Per-Hour.
RBL-статус свого IP — dig +short <reverse-ip>.zen.spamhaus.org, порожньо = чисто.
