Postfixがきりの良い時間にアクセスすると遅い

背景

ユーザから「cronがキックするスクリプトがメールを送るとPostfixからの応答が遅くタイムアウトが起きている」と報告された。

結論

nslcdのレスポンスが遅いことが原因だった。きりの良い時間はLDAPのアクセスが多く、負荷が高まるためレスポンスが遅くなっている。対象のPostfixは動作上LDAPが必要なく、nslcdがLDAPの応答がない場合にさっさとタイムアウトするようにすることで改善した。

調査

最初はmilter、saslauthdを疑っていたのだが、両者を外した状態で検証しても改善しない。 master.cf, main.cfのパラメタも変えてみたが改善しない。回りくどいことはやめて、straceでプロセスを追ってみた。

$ ps auxww | grep master
root     12984  0.0  0.0 107452   948 pts/1    S+   16:07   0:00 grep master
$ sudo strace -tt -s 2048 -f -p 12984 -t > strace.20151105 2>&1

1:35:01 clone(Process 9798 attached
[pid 12984] 21:35:01 clone(Process 9799 attached

9799と9788はmasterがcloneを実行して作成したプロセス。

[pid  9799] 21:35:01 open("/lib64/libnss_ldap.so.2", O_RDONLY) = 1

ldapライブラリを読み込んでいる

[pid  9799] 21:35:01 execve("/usr/libexec/postfix/smtpd", ["smtpd", "-n", "465", "-t", "inet", "-u", "-o", "stress=", "-s", "2", "-o", "smtpd_sasl_auth_enable=yes", "-o", "smtpd_sasl_security_options=noanonymous"], [/* 4 vars */]
 <unfinished ...>

9799はmasterからsmtpdに転身する。

9799だけに関して見ると以下のように1秒から14秒まで飛んでいる。

[pid  9799] 21:35:01 munmap(0x7fc9a8b3b000, 34862) = 0
[pid  9799] 21:35:01 socket(PF_FILE, SOCK_STREAM, 0) = 10
[pid  9799] 21:35:01 connect(10, {sa_family=AF_FILE, path="/var/run/nslcd/socket"}, 110) = 0
[pid  9799] 21:35:01 select(1024, NULL, [10], NULL, {9, 999999}) = 1 (out [10], left {9, 999995})
[pid  9799] 21:35:01 sendto(10, "\1\0\0\0\213\23\0\0\7\0\0\0postfix", 19, MSG_NOSIGNAL, NULL, 0) = 19
[pid  9799] 21:35:01 select(1024, [10], NULL, NULL, {59, 999999} <unfinished ...>
[pid  9799] 21:35:14 <... select resumed> ) = 1 (in [10], left {46, 803711})
[pid  9799] 21:35:14 read(10, "\1\0\0\0\213\23\0\0\3\0\0\0", 1024) = 12
[pid  9799] 21:35:14 close(10)          = 0

/var/run/nslcd/socketにデータを送りつけるところで止まっているように見える。 nslcdはLDAPでユーザ情報を引くときに通信するデーモンらしい。 http://arthurdejong.org/nss-pam-ldapd/nslcd.conf.5

Postfixという名前のユーザはローカルに存在するので、LDAPに聞きに行く必要は無いはずだがよくわからない。 /etc/nsswitch.conf上もfilesが優先されていた。

とりあえず、以下のようにnslcdのタイムアウト値を減らしたところ、レスポンスが改善した。

bind_timelimit 2
timelimit 3

ちょっと釈然としないが、よいとしよう。