メールサーバでユーザ認証の暗号化を強制したときの話。（設定とかでなくログの読み方）

はじめに。本文は実質的に以下の投稿の続きです。

> https://qiita.com/qiitamatumoto/items/608b56e63eec26702caf
> CentOS6.6でメール関連のSSLログの取得および調査
こちらで述べているSSL/TLSのログを詳細に記録する設定をすでに行っていることを前提としています。

1.職場のメールサーバ
複数管理しているんですが、とある部署のメールサーバは2006年ごろに前任の方が構築したものです。OS更新は二回ほど行ってますが、基本設定はそのまま引き継いでいたため、

- 職場内: 非暗号化設定メールの読み書き可
- 職場外: 非暗号化設定のメールの読み書きは不可

になっていました。当時は暗号化(SSL/TLS)対応のメールリーダーも少なく妥当な設定と思います。

それなんですが、まぁそれから11年経ちまして、非暗号化は禁止して暗号化のみにしてもよいのではと思いました。

なおここでいう暗号化は、「クライアントPC」から「メールサーバ」にたまっているメールの受信、「クライアントPC」から「メールサーバ」にメールを送信するときにに「ユーザの認証情報」(ID/Password)の送信時に暗号化されるかという話です。具体例を挙げると

- メールを受信するときは、他人がメールを読めないように、POP/IMAPサーバに対してユーザ認証を行います。
- メールを送信するときは、第三者がSMTPサーバを無断利用しないようにSMTPサーバに対してユーザ認証情報を行います。

これらのユーザ認証情報が暗号化されるかという話です。

(蛇足)「メールサーバ」と「メールサーバ」との送受信は多くの場合は暗号化されません。そのため、サーバ間のネットワークに盗聴者がいた場合は、本稿で述べる対策はあまり意味はありません(^_^;　メールの本文は読み放題でしょうね。今回の暗号化対策はユーザの認証情報を横取りされないための対策と考えていただいてよいかとおもいます。

2.現在の設定

OS: CentOS6.9/64bit
IMAP/POPサーバ: dovecot-2.0.9-22.el6.x86_64
SMTPサーバ: postfix-2.6.6-8.el6.x86_64

また設定で、

> https://qiita.com/qiitamatumoto/items/608b56e63eec26702caf
> CentOS6.6でメール関連のSSLログの取得および調査
こちらで述べているSSL/TLSのログを詳細に記録する設定をすでに行っていることを前提としています。

3.ログを精査
具体的にどんなログになっているのかの例をあげます。またログの抽出についてのべます。

3.1.dovecot:

非暗号化通信の場合

```
Oct 30 08:52:45 mail dovecot: imap-login: Login: user=<USER-NAME>, method=PLAIN, rip=CLIENT-PC-IP, lip=SERVER-IP, mpid=25607
Oct 30 09:23:03 mail dovecot: imap(USER-NAME): Disconnected: Logged out bytes=231/634

Oct 30 08:30:06 mail dovecot: pop3-login: Login: user=<USER-NAME>, method=PLAIN, rip=CLIENT-PC-IP, lip=SERVER-IP, mpid=24787
Oct 30 08:30:06 mail dovecot: pop3(USER-NAME): Disconnected: Logged out top=0/0, retr=7/23260, del=7/7, size=23141
```

暗号化通信の場合

```
Oct 29 03:34:08 mail dovecot: imap-login: Login: user=<USER-NAME>, method=PLAIN, rip=CLIENT-PC-IP, lip=SERVER-IP, mpid=26295, TLS, TLSv1.2 with cipher DHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Oct 29 03:34:11 mail dovecot: imap(USER-NAME): Disconnected: Logged out bytes=457/1340

Oct 30 08:45:51 mail dovecot: pop3-login: Login: user=<USER-NAME>, method=PLAIN, rip=CLIENT-PC-IP, lip=SERVER-IP, mpid=25313, TLS, TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)
Oct 30 08:45:52 mail dovecot: pop3(USER-NAME): Disconnected: Logged out top=0/0, retr=1/3840, del=0/184, size=13366162

```

というようになっていました。 少々乱暴ですが、こんな感じでログの摘出ができます。

```
$ grep "pop3-login: Login:" /var/log/maillog*|  awk '{print $8,":",$13}'|sort | uniq
user=<USER-1>, : TLS,
user=<USER-2>, : 
user=<USER-3>, : TLS,

$ grep "imap-login: Login:" /var/log/maillog*|  awk '{print $8,":",$13}'|sort | uniq
user=<USER-1>, : TLS,
user=<USER-2>, : TLS,
user=<USER-3>, : 
```

ユーザ名の横に「TLS」が無いユーザが非暗号化通信を行っています。

3.2.postfix
Dovecotは簡単にログの摘出ができたのですが、Postfixはログが複数行のため、少々厄介でした。

メール送信時のユーザ認証はSASLが使われています。sasl_method, sasl_usernameをキーワードにログを検索すればよいです。

非暗号化通信の場合

```
Oct 29 07:00:07 mail postfix/smtpd[29629]: connect from CLIENT-PC[CLIENT-PC-IP]
Oct 29 07:00:07 mail postfix/smtpd[29629]: 9AE13C0073: client=CLIENT-PC[CLIENT-PC-IP], sasl_method=login, sasl_username=USER-NAME
```

暗号化通信の場合

```
Oct 29 09:28:27 mail postfix/smtpd[913]: connect from CLIENT-PC[CLIENT-PC-IP]
Oct 29 09:28:27 mail postfix/smtpd[913]: setting up TLS connection from CLIENT-PC[CLIENT-PC-IP]
Oct 29 09:28:27 mail postfix/smtpd[913]: Anonymous TLS connection established from CLIENT-PC[CLIENT-PC-IP]: TLSv1.2 with cipher DHE-RSA-AES256-G
CM-SHA384 (256/256 bits)
Oct 29 09:28:28 mail postfix/smtpd[913]: F15DDC0073: client=CLIENT-PC[CLIENT-PC-IP], sasl_method=PLAIN, sasl_username=USER-NAME
```

非暗号化通信と暗号化通信との違いは 「setting up TLS connection」というような行があるか無しかになります。そのため、ログの抽出は、3ステップ必要になりました。

まず、saslを使っているユーザの抽出。

```
$ grep sasl /var/log/maillog* | awk '{print $9}'|sort | uniq|more
sasl_username=USER-1
sasl_username=USER-2
sasl_username=USER-3
```

上記で抽出された各ユーザに対して以下の作業の「USER-NAME」を置き換えてを実施します。

```
$ cat /var/log/maillog* | grep sasl_username=USER-NAME | awk -F"\\\\]" '{print $1"]"}' > /tmp/list.txt
$ fgrep -f /tmp/list.txt /var/log/maillog* | less
```

上記で各SASL利用時に暗号化通信が行われているか確認できます。

バグ：上記の/tmp/list.txtは以下のような内容になっています。

```/tmp/list.txt
Dec  4 10:46:05 mail postfix/smtpd[24099]
Dec  4 16:35:43 mail postfix/smtpd[4041]
Dec  4 16:48:50 mail postfix/smtpd[4684]
Dec  4 17:27:16 mail postfix/smtpd[6423]
```

ようは、smtpdの実行時間とプロセス番号でfgrepしているだけですね。それなので、暗号化通信の途中で秒数が変わるとログの抽出時に情報が欠けます。。

4.ログ調査の結果

IMAP利用者19名中、非暗号化2名
POP利用者13名中、非暗号化6名
SMTPサーバ利用者26名中、非暗号化8名

となりました。一人で複数クライアントをお使いの方が居ましたので計算は合いません。

5.暗号化通信を強化を周知

非暗号化通信の方のお使いのメールリーダーを今まで私に送られてきたメールのヘッダ「User-Agent」および「X-Mailer」から調査したところ、

- Thunderbird
- HidemaruMail
- EdMax
- Outlook系

でした。それぞれ調査したところ、暗号化対応可能のようでしたので、メールで周知しご対応していただいた方はすぐに対応いただきました。一部の方には直接お部屋に伺い対応しました。

一件、問い合わせがありました。

- メールリーダーは使ってない。Webメールのみの利用だ。

ログを精査すると毎朝7時に非暗号化通信で投函されていました。おそらく何らかの機材が定期的に送ってるのでは？と回答したところ、そうでしたと回答があり、その後止まりました。具体的に何だったのかは不明です。

6.暗号化通信の強制

具体的には次の設定になります。すでにSSL周りの通信設定は終わっていると想定します。

CentOS6.9で確認。

```/etc/postfix/main.cf
smtpd_tls_auth_only=yes
```

```/etc/dovecot/conf.d/10-ssl.conf
ssl = required
```

以上になります。