PflogsummでPostfixのメールログを解析してみる
こんにちは、技術部のfです。
サーバからメールを送信する時にはMTA(Mail Transfer Agent:メール転送エージェント)という機能を利用します。代表的なMTAとしてはPostfixやSendmail、qmailなどが挙げられます。
今回はPostfixのメールログを解析することができる「Pflogsumm」というツールについて少し触ってみたいと思います。
Pflogsummとは
manコマンドでマニュアルを見てみると、NAMEのセクションに以下の記述があります。
(※マニュアルはインストール後に確認しています)
# man pflogsumm
NAME
pflogsumm.pl – Produce Postfix MTA logfile summary
Copyright (C) 1998-2010 by James S. Seymour, Release 1.1.5
PflogsummとはPostfixのログファイルの要約を作成してくれるツールと簡単に紹介されています。
Postfixのpf、logfileのlog、summaryのsummを繋げてPflogsumm、といったところでしょうか。
具体的にどういったことができるのか、インストールして確かめてみようと思います。
Pflogsummをインストールする
今回は AlmaLinux 8 の環境に対してPflogsummをインストールしてみます。
# cat /etc/almalinux-release
AlmaLinux release 8.7 (Stone Smilodon)
Pflogsummはdnfでpostfix-perl-scriptsパッケージをインストールすることで利用できますので、早速インストールしてみます。
# dnf install postfix-perl-scripts 依存関係が解決しました。 ================================================================================================================================================ パッケージ アーキテクチャー バージョン リポジトリー サイズ ================================================================================================================================================ インストール: postfix-perl-scripts x86_64 2:3.5.8-4.el8 appstream 79 k 依存関係のインストール: perl-Bit-Vector x86_64 7.4-11.el8 appstream 171 k perl-Carp-Clan noarch 6.06-6.el8 appstream 32 k perl-Date-Calc noarch 6.4-9.el8 appstream 212 k トランザクションの概要 ================================================================================================================================================ インストール 4 パッケージ ダウンロードサイズの合計: 494 k インストール後のサイズ: 1.3 M これでよろしいですか? [y/N]: y (省略) インストール済み: perl-Bit-Vector-7.4-11.el8.x86_64 perl-Carp-Clan-6.06-6.el8.noarch perl-Date-Calc-6.4-9.el8.noarch postfix-perl-scripts-2:3.5.8-4.el8.x86_64 完了しました!
特に問題なく完了しました。
インストールした postfix-perl-scripts パッケージに含まれるファイルの一覧を見てみます。
# rpm -ql postfix-perl-scripts
/usr/sbin/pflogsumm
/usr/sbin/qshape
/usr/share/doc/postfix/pflogsumm-faq.txt
/usr/share/man/man1/pflogsumm.1.gz
/usr/share/man/man1/qshape.1.gz
マニュアルとpflogsummコマンド、qshapeコマンドの2つのみという非常にシンプルなパッケージとなっていました。
ちなみにqshapeはメールキューの解析に使用する為のコマンドのようです。
今回はpflogsummが目的のため詳細は割愛しますが、以下のサイトなどで使い方が紹介されていますので、興味がある方はぜひ。
https://www.postfix-jp.info/trans-2.3/jhtml/QSHAPE_README.html
Pflogsummを使ってみる
まずは–helpを打ってみます。
# pflogsumm –help
usage: pflogsumm -[eq] [-d ] [–detail ]
[–bounce-detail ] [–deferral-detail ]
[-h ] [-i|–ignore-case] [–iso-date-time] [–mailq]
[-m|–uucp-mung] [–no-no-msg-size] [–problems-first]
[–rej-add-from] [–reject-detail ] [–smtp-detail ]
[–smtpd-stats] [–smtpd-warning-detail ]
[–syslog-name=string] [-u ] [–verbose-msg-detail]
[–verp-mung[=]] [–zero-fill] [file1 [filen]]
pflogsumm –[version|help]
オプションの意味はマニュアルを見るしかなさそうですが、指定可能なオプションは多数存在しているようです。
試しにpflogsummコマンドを実行…といきたいところですが、あまりに検証環境でのメールログの出力がなかったので、一週間分のメールログのサンプルを今話題のChatGPTに出力してもらいました。
4/1から4/7までのPostfixのメールログのサンプルを1日ずつ出力してもらいつつ、適当にバウンスなどのログも入れてもらっています。
内容はこんな感じです。
# head maillog
Apr 1 08:00:11 mailserver postfix/smtpd[12300]: connect from sender01.example.com[192.0.2.10]
Apr 1 08:00:12 mailserver postfix/smtpd[12300]: 0102030405: client=sender01.example.com[192.0.2.10], sasl_method=PLAIN, sasl_username=user01@example.com
Apr 1 08:00:12 mailserver postfix/cleanup[12301]: 0102030405: message-id=20230401080011.0102030405@mailserver.example.com
Apr 1 08:00:12 mailserver postfix/qmgr[12302]: 0102030405: from=user01@example.com, size=512, nrcpt=1 (queue active)
Apr 1 08:00:13 mailserver postfix/smtp[12303]: 0102030405: to=recipient01@example.org, relay=mx.example.org[203.0.113.10]:25, delay=1.0, delays=0.1/0.01/0.5/0.4, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 102030405A)
Apr 1 08:00:13 mailserver postfix/qmgr[12302]: 0102030405: removed
Apr 1 08:00:13 mailserver postfix/smtpd[12300]: disconnect from sender01.example.com[192.0.2.10] ehlo=2 starttls=1 auth=1 mail=1 rcpt=1 data=1 quit=1 commands=9
Apr 2 14:30:22 mailserver postfix/smtpd[12310]: connect from sender02.example.com[192.0.2.20]
Apr 2 14:30:23 mailserver postfix/smtpd[12310]: 020406080A: client=sender02.example.com[192.0.2.20], sasl_method=PLAIN, sasl_username=user02@example.com
Apr 2 14:30:23 mailserver postfix/cleanup[12311]: 020406080A: message-id=20230402143022.020406080A@mailserver.example.com
ちゃんと例示用のドメインやIPアドレスで出力してくれており、時間帯もランダムに指定してくれているようです。SMTP認証もしていますね。
それではChatGPTに生成してもらったメールログに対し、pflogsummコマンドを実行してみます。
# pflogsumm maillog
Grand Totals
------------
messages
7 received
6 delivered
0 forwarded
1 deferred (1 deferrals)
1 bounced
0 rejected (0%)
0 reject warnings
0 held
0 discarded (0%)
11776 bytes received
11972 bytes delivered
7 senders
1 sending hosts/domains
6 recipients
2 recipient hosts/domains
Per-Day Traffic Summary
-----------------------
date received delivered deferred bounced rejected
--------------------------------------------------------------------
Apr 1 2023 1 1
Apr 2 2023 1 1
Apr 3 2023 1 1
Apr 4 2023 1 1
Apr 5 2023 1 1
Apr 6 2023 1 0 1
Apr 7 2023 1 1 0 1
Per-Hour Traffic Daily Average
------------------------------
time received delivered deferred bounced rejected
--------------------------------------------------------------------
0000-0100 0 0 0 0 0
0100-0200 0 0 0 0 0
0200-0300 0 0 0 0 0
0300-0400 0 0 0 0 0
0400-0500 0 0 0 0 0
0500-0600 0 0 0 0 0
0600-0700 0 0 0 0 0
0700-0800 0 0 0 0 0
0800-0900 0 0 0 0 0
0900-1000 0 0 0 0 0
1000-1100 0 0 0 0 0
1100-1200 0 0 0 0 0
1200-1300 0 0 0 0 0
1300-1400 0 0 0 0 0
1400-1500 0 0 0 0 0
1500-1600 0 0 0 0 0
1600-1700 0 0 0 0 0
1700-1800 0 0 0 0 0
1800-1900 0 0 0 0 0
1900-2000 0 0 0 0 0
2000-2100 0 0 0 0 0
2100-2200 0 0 0 0 0
2200-2300 0 0 0 0 0
2300-2400 0 0 0 0 0
Host/Domain Summary: Message Delivery
--------------------------------------
sent cnt bytes defers avg dly max dly host/domain
-------- ------- ------- ------- ------- -----------
5 6144 1 1.1 s 1.4 s example.org
1 5828 0 0.5 s 0.5 s example.com
Host/Domain Summary: Messages Received
---------------------------------------
msg cnt bytes host/domain
-------- ------- -----------
7 11776 example.com
Senders by message count
------------------------
1 user01@example.com
1 user02@example.com
1 user03@example.com
1 user04@example.com
1 user05@example.com
1 user06@example.com
1 user07@example.com
Recipients by message count
---------------------------
1 user07@example.com
1 recipient01@example.org
1 recipient02@example.org
1 recipient03@example.org
1 recipient04@example.org
1 recipient05@example.org
Senders by message size
-----------------------
3072 user07@example.com
2560 user06@example.com
2048 user05@example.com
1536 user03@example.com
1024 user02@example.com
1024 user04@example.com
512 user01@example.com
Recipients by message size
--------------------------
5828 user07@example.com
2048 recipient05@example.org
1536 recipient03@example.org
1024 recipient02@example.org
1024 recipient04@example.org
512 recipient01@example.org
message deferral detail
-----------------------
smtp (total: 1)
1 4.3.0 Temporary problem, please try again later (in reply ...
message bounce detail (by relay)
--------------------------------
mx.example.org[203.0.113.70]:25 (total: 1)
1 User unknown in local recipient table (in reply to RCPT TO comm...
message reject detail: none
message reject warning detail: none
message hold detail: none
message discard detail: none
smtp delivery failures: none
Warnings: none
Fatal Errors: none
Panics: none
Master daemon messages: none
ちょっと長いですが、こんな感じの結果が出力されました。
「Grand Totals」では解析対象のメールログ全体の送信や受信、バウンス、キューに溜まったメールなどの総数が、
「Per-Day Traffic Summary」では1日あたりの各ステータスごとのメールの総数が、
「Per-Hour Traffic Daily Average」では時間帯ごとの各ステータスのメールの総数が確認できるようです。
また、「どのドメイン、メールアドレスに何件メールを送信しているか」といった集計や、バウンスや拒否、キューに溜まったメールのエラーメッセージごとの件数の集計なども行ってくれるようです。
ちなみに上記の結果では「Per-Hour Traffic Daily Average」が全て0件になってしまっていますが、件数が少ないと集計結果が0件になってしまうようです。
試しに別環境のメールログで解析してみたところ、以下のように時間帯ごとの集計結果が出力されました。
Per-Hour Traffic Daily Average
------------------------------
time received delivered deferred bounced rejected
--------------------------------------------------------------------
0000-0100 40 175 0 1 9
0100-0200 22 103 0 1 6
0200-0300 133 989 0 1 6
0300-0400 87 626 0 2 14
0400-0500 81 277 0 3 7
0500-0600 54 150 0 1 12
0600-0700 38 70 0 1 11
0700-0800 35 142 0 1 8
0800-0900 75 187 0 2 11
0900-1000 31 104 0 1 11
1000-1100 34 198 0 2 5
1100-1200 13 45 0 1 12
1200-1300 21 65 0 2 16
1300-1400 19 98 0 1 9
1400-1500 31 154 0 1 8
1500-1600 20 137 0 2 10
1600-1700 44 177 0 1 10
1700-1800 29 145 0 2 10
1800-1900 16 91 0 1 8
1900-2000 38 47 0 2 11
2000-2100 28 102 0 1 8
2100-2200 12 38 0 1 9
2200-2300 18 34 0 1 4
2300-2400 20 100 0 1 6
おわりに
PflogsummはRHEL系OSだとdnfでインストールすることができ、複雑なオプションを指定せずとも簡単にメールログの解析を行うことができました。
活用方法は色々考えられそうですが、どの時間帯やどの曜日にメール送受信数が多いか？といったメールサーバの利用傾向を調べたり、送信に失敗しているメールのエラー傾向を調べたりする時に使えそうです。
送信先のメールボックスが存在しない場合であれば単純な宛先ミスやメールアドレスが削除された可能性が考えられますが、例えばスパムリストに登録されていて拒否された、メールサーバのIPレピュテーションが低く送信先メールサーバに拒否された、といったエラーメッセージが散見される場合は、不審なメールを送信していないか、またSPFレコードやIPアドレスの逆引き設定といったなりすまし対策が行われているか等を見直す必要があるかもしれません。
メールアカウントのパスワードを推測しやすい簡単なものに設定している場合、パスワードを割り出されて不特定多数にスパムメールを送信されてしまうこともありますので、なるべく長い文字数かつ大文字小文字記号を混ぜた複雑なパスワードを設定するようにしましょう。
