改訂(2018/1/25): CentOS6.6からCentOS6.9およびCentOS7.4用に改訂
#はじめに
SSL関係の脆弱性の報道はよくありますが、SSLを使っているのはWeb(HTTP over SSL)だけではなくメールも使っています。
現在使っているSSL通信プロトコルの調査をするためにログを取得する方法、およびログを読んで調査する方法を述べます。
なお、すでに基本的なSSLの設定は行われていて運用されていいる事を想定しています。
2.メール関係のプロトコル
メール関係では以下のプロトコルでSSLが使われますかね。
-smtp + starttls (SSL無しで繋いでstartls命令でSSL通信開始)
port: 25/tcp, 587/tcp
-smtps (いきなりSSL通信)
port: 465/tcp
-imap + starttls
port: 143/tcp
-imaps
port: 993/tcp
-pop3 + starttls
port: 110/tcp
-pop3s
port: 995/tcp
上記のログを取ってみます。
#標準設定でのSSLログの取得設定
メールサーバを提供するアプリケーションは色々種類がありますが、今回はOSに標準で入っているpostfixとdovecotを想定します。
CentOS6.9/7.4の標準設定では、メールのログファイルは以下の所にあります。1週間ごとにファイルがバックアップされていきます。標準では4週間保存されます。(保存期間を増やす場合は/etc/logrotate.confの rotateの行を変更ください。HDD残量が厳しい場合はcompressを指定してください。古いログは圧縮されます。)
/var/log/maillog (最新)
/var/log/maillog-20180121 (バックアップ)
/var/log/maillog-20180114 (バックアップ)
...
上記のメールログには標準ではSSLは詳細なログが記録されません。
以下のような設定をすることによりSSLの詳細ログが取得できますので、設定を行なっておいて、最低1週間程度まって下さい。できれば一か月。。
注意点： postfixの設定やログではsmtpd(d有り)とsmtp(d無し)の違いに注意して下さい。smtpdは受信時の設定、smtpは送信時の設定です。
##postfixの設定
postfixのmain.cfに加筆してください。
注意: postfixの設定やログではsmtpd(d有り)とsmtp(d無し)の違いに注意して下さい。smtpdは受信時の設定、smtpは送信時の設定です。
# メール受信時のSSLログ
smtpd_tls_loglevel = 1
# メール送信時のSSLログ
smtp_tls_loglevel = 1
# おまけ:
# 受信時のSSL暗号化はテストされる方が多いのですが、
# 送信時の設定を忘れている場合がよくあるようです。
# 送信時のSSLを有効にする設定。
smtp_use_tls = yes
smtp_tls_security_level = may
##dovecotの設定
標準設定の最後に%kを加筆しています。(CentOS6.9/CentOS7.4いずれも同じ)
#login_log_format_elements = user=<%u> method=%m rip=%r lip=%l mpid=%e %c
login_log_format_elements = user=<%u> method=%m rip=%r lip=%l mpid=%e %c %k
OSを再起動することにより、上記設定が有効になります。
(執筆メモ：上記はブログ掲載用。実際運用しているCentOS7.xサーバの設定と違う。)
#一週間以上経過後、ログが溜まってからの作業
再掲になりますが、メールのログは(/var/log/maillog)です。このファイルから抜粋したログを例示します。
以下はpostfixのメール受信の例。 postfix/smtpd の行がSSL有りでメールを受信したときのログです。(smtpにd有り)
Jan 21 23:37:16 mail postfix/smtpd[23240]: Anonymous TLS connection established mail.example.com[203.0.113.1]: TLSv1.2 with cipher AES256-SHA256 (256/256 bits)
上記ログはSSLのバージョンはTLSv1.2でcipherは ADH-AES256-GCM-SHA384 (256/256 bits)ということですね。
送信の例。postfix/smtpの行がSSL有りでメールを送信したときのログです。 (smtpにd無し)
Jan 22 04:02:38 mail postfix/smtp[28472]: Trusted TLS connection established to mail.example.com[203.0.113.1]:25: TLSv1.2 with cipher ECDHE-RSA-AES256-SHA384 (256/256 bits)
続いてdovecotですが、pop3-login/imap-loginでpop3でログインしたかimapでログインしたか分かります。
Jul 26 03:13:12 mail dovecot: pop3-login: Login: user=<USER-NAME>, method=PLAIN, rip=198.51.100.100, lip=198.51.100.1, mpid=19924, TLS, TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)
Jul 26 03:23:32 mail dovecot: imap-login: Login: user=<USER-NAME>, method=PLAIN, rip=198.51.100.101, lip=198.51.100.1, mpid=20141, TLS, TLSv1 with cipher RC4-MD5 (128/128 bits)
#集計スクリプト
集計のための簡単なスクリプトを用意します。
cat-XXがログを標準出力に出すスクリプト。count-XXが集計。grep-XXが検索です。
::::::::::::::
./cat-maillog.sh
サーバにあるメールのログを全て標準出力に出力。
ログを圧縮してないときはgzipから後を消してください。
::::::::::::::
cat /var/log/maillog /var/log/maillog*[0-9]; gzip -dc /var/log/maillog*.gz
::::::::::::::
./cat-maillog0.sh
サーバにあるメールのログで最近のだけ標準出力に出力.。
改訂(2018/1/25): 最近の1週間程度に修正。
::::::::::::::
cat `ls -t /var/log/maillog* | head -2`
::::::::::::::
./count-dovecot-tls.sh
dovecotのSSLログを集計
(執筆メモ：ブログ掲載用。実際運用しているCentOS7.xサーバのスクリプトは違う。)
::::::::::::::
grep dovecot: | grep -v "Disconnected" | grep "with cipher" | perl -pe 's/^.*, TLS, //' | sort | uniq -c
::::::::::::::
./count-postfix-receive-tls.sh
postfixのメール受信時のSSLログを集計
::::::::::::::
fgrep "postfix/smtpd[" | grep "with cipher"| perl -ne '/^.* ([\w\.]+ with cipher .*)$/;print $1."\n";' | sort | uniq -c
::::::::::::::
./count-postfix-send-tls.sh
postfixのメール送信時のSSLログを集計
::::::::::::::
fgrep "postfix/smtp[" | grep "with cipher"| perl -ne '/^.* ([\w\.]+ with cipher .*)$/;print $1."\n";' | sort | uniq -c
::::::::::::::
./grep-dovecot-tls.sh
dovecotのSSLログをgrep
::::::::::::::
grep dovecot: | grep "with cipher" | fgrep "$1"
::::::::::::::
./grep-postfix-receive-tls.sh
postfixのメール受信時のSSLログをgrep
::::::::::::::
fgrep "postfix/smtpd[" | grep "with cipher"| fgrep "$1"
::::::::::::::
./grep-postfix-send-tls.sh
postfixのメール送信時のSSLログをgrep
::::::::::::::
fgrep "postfix/smtp[" | grep "with cipher"| fgrep "$1"
上記のファイルをそれぞれ作成しchmod +xしてください。
#集計およびログの読み方
補足(2018/1/25): 以下CentOS6.6の時点のログです。細微な変更がある可能性あり。
メールログとスクリプトを使って、現在使われているSSLプロトコルを集計してみます。
dovecotのログの集計は以下のスクリプトで出来ます。
(ここ最近の1週間程度のログのみ集計)
# ./cat-maillog0.sh | ./count-dovecot-tls.sh
459 TLSv1 with cipher AES128-SHA (128/128 bits)
1174 TLSv1 with cipher AES256-SHA (256/256 bits)
5940 TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)
1626 TLSv1 with cipher RC4-MD5 (128/128 bits)
1179 TLSv1.2 with cipher DHE-RSA-AES128-GCM-SHA256 (128/128 bits)
12730 TLSv1.2 with cipher DHE-RSA-AES128-SHA (128/128 bits)
1 TLSv1.2 with cipher RC4-SHA (128/128 bits)
(サーバにある全てのログを集計)
# ./cat-maillog.sh | ./count-dovecot-tls.sh
(省略)
各行の最初の数字が接続数で、接続に使われたSSLプロトコルです。
近年ではRC4の暗号化レベルは十分とみなされていないようですので、RC4-MD5, RC4-SHAは止めたよさそうですね。
RC4-MD5を使っているクライアントIPを調べてみます。./grep-dovecot-tls.sh の引数にSSLプロトコルを指定して下さい。ダブルクオートで括ってください。
./cat-maillog0.sh | ./grep-dovecot-tls.sh "TLSv1 with cipher RC4-MD5"
Jul 26 03:13:27 mail dovecot: imap-login: Login: user=<USER-NAME>, method=PLAIN, rip=203.0.113.1, lip=198.51.100.1, mpid=19930, TLS, TLSv1 with cipher RC4-MD5 (128/128 bits)
(大量に表示されますので省略)
「rip」は接続してきたクライアントのIPです。「lip」はメールサーバのIPです。ですので、IPアドレス203.0.113.1がRC4-MD5を使って接続してきたクライアントになります。
実サーバでUSER-NAMEに表示されたユーザに聞き取り調査したところ、AUの携帯電話でした。
続いて、postfixの集計をします。
繰り返しになりますが、postfixがメールを受信したときのログはsmtpd (d有り)、送信したときのログはsmtp (d無し)です。
(メール受信時のログ。ここ最近のログのみ。)
# ./cat-maillog0.sh | ./count-postfix-receive-tls.sh
5 SSLv3 with cipher DHE-RSA-AES256-SHA (256/256 bits)
10 TLSv1 with cipher ADH-AES256-SHA (256/256 bits)
8 TLSv1 with cipher AES128-SHA (128/128 bits)
20 TLSv1 with cipher AES256-SHA (256/256 bits)
6 TLSv1 with cipher DHE-RSA-AES128-SHA (128/128 bits)
297 TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)
20 TLSv1 with cipher DHE-RSA-CAMELLIA256-SHA (256/256 bits)
7 TLSv1 with cipher EDH-RSA-DES-CBC3-SHA (128/168 bits)
5 TLSv1 with cipher RC4-MD5 (128/128 bits)
2 TLSv1 with cipher RC4-SHA (128/128 bits)
8 TLSv1.1 with cipher DHE-RSA-AES256-SHA (256/256 bits)
1225 TLSv1.2 with cipher ADH-AES256-GCM-SHA384 (256/256 bits)
18 TLSv1.2 with cipher AES128-GCM-SHA256 (128/128 bits)
4 TLSv1.2 with cipher AES256-GCM-SHA384 (256/256 bits)
1 TLSv1.2 with cipher DHE-RSA-AES128-GCM-SHA256 (128/128 bits)
236 TLSv1.2 with cipher DHE-RSA-AES128-SHA (128/128 bits)
50 TLSv1.2 with cipher DHE-RSA-AES256-GCM-SHA384 (256/256 bits)
1 TLSv1.2 with cipher DHE-RSA-AES256-SHA (256/256 bits)
1 TLSv1.2 with cipher RC4-SHA (128/128 bits)
(メール送信時のログ。ここ最近のログのみ。)
# ./cat-maillog0.sh | ./count-postfix-send-tls.sh
903 TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)
1 TLSv1 with cipher DHE-RSA-CAMELLIA256-SHA (256/256 bits)
179 TLSv1.2 with cipher AES256-GCM-SHA384 (256/256 bits)
11 TLSv1.2 with cipher DHE-RSA-AES256-GCM-SHA384 (256/256 bits)
315 TLSv1.2 with cipher ECDHE-RSA-AES128-GCM-SHA256 (128/128 bits)
126 TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
上記出力で後半のメール送信時のログは特に問題ないと思いますが、前半のメール受信時のログではRC4等脆弱性のあるSSLプロトコルが使われているようです。
受信時のログでRC4-SHAの送り主と送り先を調べてみます。./grep-postfix-receive-tls.sh の引数にSSLプロトコルを指定して下さい。ダブルクオートで括ってください。
# ./cat-maillog0.sh | ./grep-postfix-receive-tls.sh "TLSv1 with cipher RC4-SHA"
Jul 23 19:44:19 mail postfix/smtpd[18502]: Anonymous TLS connection established from mail.example.com[203.0.113.99]: TLSv1 with cipher RC4-SHA (128/128 bits)
Jul 23 23:50:55 mail postfix/smtpd[21825]: Anonymous TLS connection established from mail.example.com[203.0.113.99]: TLSv1 with cipher RC4-SHA (128/128 bits)
7月23日の19:44頃と23:50頃の二つのログが出てきました。19:44のほうを調べてみます。
fgrepの引数にhostnameとIPの所をコピペして実行してみてください。
# ./cat-maillog0.sh | fgrep "mail.example.com[203.0.113.99]"
Jul 23 19:44:19 mail postfix/smtpd[18502]: connect from mail.example.com[203.0.113.99]
Jul 23 19:44:19 mail postfix/smtpd[18502]: setting up TLS connection from mail.example.com[203.0.113.99]
Jul 23 19:44:19 mail postfix/smtpd[18502]: Anonymous TLS connection established from mail.example.com[203.0.113.99]: TLSv1 with cipher RC4-SHA (128/128 bits)
Jul 23 19:44:20 mail postfix/smtpd[18502]: 9D49D61C77: client=mail.example.com[203.0.113.99]
Jul 23 19:44:21 mail postfix/smtpd[18502]: disconnect from mail.example.com[203.0.113.99]
上記の下から２行目に「9D49D61C77」というのがありますが、これはメールのQUEUE-IDです。これを使ってさらに検索してみます。
# ./cat-maillog0.sh | fgrep "9D49D61C77"
Jul 23 19:44:20 mail postfix/smtpd[18502]: 9D49D61C77: client=mail.example.com[203.0.113.99]:
Jul 23 19:44:21 mail postfix/cleanup[18506]: 9D49D61C77: message-id=<123456478@mail.example.com>
Jul 23 19:44:21 mail postfix/qmgr[2192]: 9D49D61C77: from=<USER-NAME-FROM@example.com>, size=11014, nrcpt=1 (queue active)
Jul 23 19:44:21 mail postfix/local[18507]: 9D49D61C77: to=<USER-NAME-TO@example.jp>, relay=local, delay=1, delays=0.95/0.01/0/0.09, dsn=2.0.0, status=sent (delivered to maildir)
Jul 23 19:44:21 mail postfix/qmgr[2192]: 9D49D61C77: removed
上記で上から4行目のfromのところに書かれているUSER-NAME-FROM@example.comが送信主。5行目のtoに書かれているUSER-NAME-TO@example.jpが送り先になります。
(注意: fromはメール本文にかかれているfromと上記ログに書かれているfromが異なる事は多々あります。スパムメールも異なることが多々ありますが、MLなどではエラーメール対策で意図的に書き換えられていることがあります。)
以上のような手順で、受信時のログを基に脆弱性のあるSSLプロトコルで送られてきたメールの送り主、送り先が調査できました。
postfixのメール送信時のログを基に送り主送り先の調査については省略します。
送信時は以下のコマンドを使って下さい。SSLプロトコルはダブルクオートで括ってください。
# ./cat-maillog0.sh | ./grep-postfix-send-tls.sh "TLSv1 with cipher DHE-RSA-CAMELLIA256-SHA"
#この記事の続き
ログをもとにした設定変更は次の記事を参考にください。
CentOS6.9/CentOS7.4でメール関連のSSLログの調査および設定変更
https://qiita.com/qiitamatumoto/items/7e22a766d77d8e9f0048
#追記(2018/1/25)
ログの細微な検討については以下の記事も参考にください。
メールサーバでユーザ認証の暗号化を強制したときの話。（設定とかでなくログの読み方）
https://qiita.com/qiitamatumoto/items/8c4341d0af9958543db4
以上。