改訂(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は送信時の設定です。

/etc/postfix/main.cf

# メール受信時の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いずれも同じ)

/etc/dovecot/conf.d/10-logging.conf

#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

以上。