dovecot / postfix と Active Directory連携時の動作調査手法

dovecot / postfix と Active Directoryを連携させようと設定してみたところ、最初はうまく動かなかった。

この動かない原因をどうやって調べていくか、というのを解説してるものがなく、非常に難儀したのでメモ書きとして残す

dovecot, postfixの現在の設定を確認

RHEL9の場合、 /etc/dovecot および /etc/postfix に設定ファイル群があるが、コメントやサブディレクトリにあるファイルとの結合により、最終的な設定が何になっているのかわかりにくい

「doveconf」および「postconf」を実行することで最終的な設定を確認することができる

また、デフォルト値と異なる部分は何かを「doveconf -n」「postconf -n」を実行することで確認できる。

なお、doveconfの場合、ssh_keyなど一部のパラメータについては「doveconf -P」と-Pオプションをつけないと実際の値が表示されない

dovecotのログ出力を増やす

ログ出力を増やすための設定がいろいろあった(Dovecot Logging)ため、 /etc/dovecot/conf.d/99-debug.conf と１つのファイルにまとめて必要ない場合は /etc/dovecot/conf.d/99-debug._conf と.conf という名前じゃなくすることで無効化できるようにした

[root@mail dovecot]# cat /etc/dovecot/conf.d/99-debug.conf
auth_debug=yes
auth_debug_passwords=yes
auth_verbose=yes
auth_verbose_passwords=yes
verbose_proctitle=yes
verbose_ssl=yes

[root@mail dovecot]#

設定後は「systemctl restart dovecot」で設定を有効にする

なお「doveadm log find」を実行するとdovecotのログがどのファイルに出力されているかを確認することができる

[root@mail dovecot]# doveadm log find
Looking for log files from /var/log
Debug: /var/log/maillog
Info: /var/log/maillog
Warning: /var/log/maillog
Error: /var/log/maillog
Fatal: /var/log/maillog
[root@mail dovecot]#

LDAP検索のログを増やす

dovecotの場合は dovecot本体への auth_verbose=yes 設定だけでLDAPでどういったqueryを投げているかも確認できる

ただ、もっと詳細を確認したい、という場合 /etc/dovecot/dovecot-ldap.conf.ext などのLDAP接続情報を書いたファイルに「debug_level」を追加することでログを増やすこともできる。

dovecot Common LDAP Settings for both auth and sieve
iredmail Turn on debug mode in Dovecot

dovecot標準値は「debug_level=0」。ログを増やす場合は「debug_level=1」、最大量に増やす場合は「debug_level=-1」とする

postfixの場合も同様に LDAP接続情報を書いたファイル /etc/postfix/ldap-mailbox.cf などに「debuglevel」を追加することでログを増やすことができる。

postfix ldap_table – Postfix LDAP client configuration

postfix標準値は「debuglevel=0」。増やす場合は「debuglevel=1」から最大量は「debuglevel=10」とする

postfixのログ出力を増やす

Postfix Debugging Howto に記載があるが正直めんどい

/etc/postfix/master.cf の smtpd起動に関して「-v」オプションか「-D」オプションをつける、という形となる。

とはいえ、postfix/dovecotを組み合わせた場合、ActiveDirectory/LDAP側の処理をdovecot側で行うということもあるので、まずはdovecot側の動作がちゃんとするのを先に確認したほうがよい。

dovecotでの認証確認

dovecotで認証動作を確認する場合、まずは「doveadm auth login ユーザ名」を実行する

[root@mail ~]# doveadm auth login testuser1@adsample.local
Password: ＜パスワード入力＞
passdb: testuser1@adsample.local auth succeeded
extra fields:
  user=testuser1@adsample.local
  uid=1000
  gid=1000
userdb extra fields:
  testuser1@adsample.local
  uid=1000
  gid=1000
  auth_mech=PLAIN
[root@mail ~]#

なお、「doveadm auth login testuser1@adsample.local パスワード」とパスワードをつけて実行すると入力しないで済むので検証時は便利（ログに残るので一時なパスワードにすること）

ただし、このdoveadm auth loginコマンドは模擬的に確認しているだけで、実際にログイン処理は行っていないようで、テストしたユーザのディレクトリがない場合でもディレクトリが作成されない。（ちゃんとログインした場合は自動的に作成される）

ldapsearchコマンドを使った検証

doveadm auth loginコマンドでうまく認証が実行できない場合、 ldapsearchコマンドを使って原因を調査していったりする。

その場合、 /etc/dovecot/conf.d/99-debug.conf の設定を有効にしてから行う。

期待通りに動作していない場合、ログにある下記のような「ldap」「base=～」「filter=～」という記述に注目する

May  2 11:18:59 mail dovecot[959]: auth-worker(1542): Debug: conn unix:auth-worker (pid=1541,uid=97): Server accepted connection (fd=14)
May  2 11:18:59 mail dovecot[959]: auth-worker(1542): Debug: conn unix:auth-worker (pid=1541,uid=97): Sending version handshake
May  2 11:18:59 mail dovecot[959]: auth-worker(1542): Debug: conn unix:auth-worker (pid=1541,uid=97): auth-worker&amp;lt;1>: Handling LIST request
May  2 11:18:59 mail dovecot[959]: auth-worker(1542): Debug: conn unix:auth-worker (pid=1541,uid=97): auth-worker&amp;lt;1>: ldap(): Performing userdb lookup
May  2 11:18:59 mail dovecot[959]: auth-worker(1542): Debug: conn unix:auth-worker (pid=1541,uid=97): auth-worker&amp;lt;1>: ldap: iterate: base=cn=Users,dc=adsample,dc=local scope=subtree filter=(objectClass=posixAccount) fields=uid
May  2 11:18:59 mail dovecot[959]: auth-worker(1542): Debug: conn unix:auth-worker (pid=1541,uid=97): auth-worker&amp;lt;1>: ldap(): Finished userdb lookup
May  2 11:18:59 mail dovecot[959]: auth-worker(1542): Debug: conn unix:auth-worker (pid=1541,uid=97): auth-worker&amp;lt;1>: Finished

上記の場合注目するのは以下の部分

base=cn=Users,dc=adsample,dc=local scope=subtree filter=(objectClass=posixAccount) fields=uid

これをldapsearchコマンドに与える

-bオプションの後ろにbase=の後ろにある「cn=Users,dc=adsample,dc=local」
-sオプションの後ろにscope=の「subtree」
そしてfilterの「objectClass=posixAccount」

ldapsearch -x -H ldaps://192.168.122.10 -D "cn=vmail,cn=Users,dc=adsample,dc=local" -w "パスワード" -b "dc=adsample,dc=local" -s subtree objectClass=posixAccount

この出力結果を確認し、fields=で指定した「uid」という項目があるかを確認します

なければfilterで指定した条件が不適切、ということとなる

fieldsで適切かなぁ、というものが出るまでfilterの条件式の調整と、fieldsで選ぶ項目の調整を行う

doveadmでメールボックスの状態確認

dovecotで認識しているメールボックスの状態を確認する「doveadm mailbox status」コマンド

全ユーザについてとりあえず全ステータスをとる場合はfieldをallにすればいい、というので「doveadm mailbox status -A all ‘*’」を実行してみる

[root@mail ~]# doveadm mailbox status -A all '*'
testuser1@adsample.local Trash messages=0 recent=0 uidnext=2 uidvalidity=1745978754 unseen=0 highestmodseq=5 vsize=0 guid=40b0b82833051c68570600003a0de1d0 firstsaved=never
testuser1@adsample.local INBOX messages=16 recent=0 uidnext=18 uidvalidity=1745978753 unseen=0 highestmodseq=22 vsize=613873 guid=3fa5f40281851168ee0500003a0de1d0 firstsaved=1746666817
testuser2@adsample.local Drafts messages=4 recent=0 uidnext=5 uidvalidity=1745978410 unseen=0 highestmodseq=9 vsize=2313 guid=fe4beb08b4d91268980500003a0de1d0 firstsaved=1746066862
testuser2@adsample.local Sent messages=28 recent=0 uidnext=35 uidvalidity=1745978409 unseen=0 highestmodseq=37 vsize=10545 guid=a28a5e0b7c201268cb0600003a0de1d0 firstsaved=1746018428
testuser2@adsample.local Trash messages=0 recent=0 uidnext=12 uidvalidity=1745978408 unseen=0 highestmodseq=11 vsize=0 guid=ab2c081a361e1268260600003a0de1d0 firstsaved=never
testuser2@adsample.local INBOX messages=9 recent=0 uidnext=15 uidvalidity=1745978407 unseen=0 highestmodseq=33 vsize=10810 guid=7e51333727841168d30500003a0de1d0 firstsaved=1746084330
testuser3@adsample.local INBOX messages=2 recent=2 uidnext=3 uidvalidity=1746166331 unseen=2 highestmodseq=3 vsize=1330 guid=7d83dc163b621468950800003a0de1d0 firstsaved=1746166331
[root@mail ~]#

ん？？ vsizeは表示されていない？…マニュアルを再度確認すると -tオプションで messages, recent, unseen, vsizeだけを表示できるとのこと

[root@mail ~]# doveadm mailbox status -A all '*' -t
testuser1@adsample.local messages=16 recent=0 unseen=0 vsize=613873
testuser2@adsample.local messages=41 recent=0 unseen=0 vsize=23668
testuser3@adsample.local messages=2 recent=2 unseen=2 vsize=1330
testuser4@adsample.local messages=0 recent=0 unseen=0 vsize=0
vmail@adsample.local messages=0 recent=0 unseen=0 vsize=0
[root@mail ~]#

messages: メール総数
recent: Recentフラグがついてるメール数(新着メール=まだメールソフトに取り込んでない)
unseen: 未読メール数
vsize: メールの総容量(バイト)