そろそろLDAPにしてみないか?
第9回 LDAPとログ
毎回テーマがコロコロと変わる本連載ですが,今回はOpenLDAPを運用する上で必須となるログの知識についてお話しします。トラブルシューティング時にログと格闘するのは管理者の必要最低限の行動です……よね。
OpenLDAPとログの設定
OpenLDAPのログはsyslogを経由して出力されます。ログの設定はいつものslapd.conf中のloglevelというパラメータで設定します。
リスト1 /etc/openldap/slapd.conf(一部)
loglevel 32
loglevelで指定可能な値は表1のように定義されています。
表1 loglevelの値とログの収集データの関係
| 値 | ログ収集データ |
|---|---|
| 1 | trace function calls |
| 2 | debug packet handling |
| 4 | heavy trace debugging |
| 8 | connection management |
| 16 | print out packets sent and received |
| 32 | search filter processing |
| 64 | configuration file processing |
| 128 | access control list processing |
| 256 | stats log connections/operations/results |
| 512 | stats log entries sent |
| 1024 | print communication with shell backends |
| 2048 | entry parsing |
以上のいずれかを設定することにより,slapdからsyslogデーモンにログが送出されるのですが,当然のことながらsyslogデーモン側でも適切に設定を行っておく必要があります。slapdからのログはlocal4というファシリティで出力されるため,/etc/syslog.confにリスト2のような設定を追記し,syslogdを再起動しておいてください。
リスト2 /etc/syslog.confに追加する設定
local4.* /var/log/ldap.log
図1 syslogdの再起動
/etc/init.d/syslog restart
syslog-ngなどのその他のsyslogデーモンを使用している場合にも,local4というファシリティのログを適切に出力できるよう設定を行ってデーモンを再起動しておく必要があります。
ログの出力例
syslogデーモンの設定を適切に行った場合,loglevelの値を変更しつつldapaddやldapsearchコマンドを実行すると,リスト3~7のようなログが出力されます。
リスト3 loglevel 512の場合
Feb 16 21:11:01 localhost slapd[4002]: conn=2 op=1 ENTRY dn="cn=suzuki,ou=People,dc=example,dc=com"
リスト4 loglevel 256の場合
Feb 16 21:11:11 localhost slapd[4044]: conn=0 fd=10 ACCEPT from IP=127.0.0.1:32785 (IP=0.0.0.0:389)
Feb 16 21:11:11 localhost slapd[4044]: conn=0 op=0 BIND dn="cn=Manager,dc=example,dc=com" method=128
Feb 16 21:11:11 localhost slapd[4044]: conn=0 op=0 BIND dn="cn=Manager,dc=example,dc=com" mech=SIMPLE ssf=0
Feb 16 21:11:11 localhost slapd[4044]: conn=0 op=0 RESULT tag=97 err=0 text=
Feb 16 21:11:11 localhost slapd[4044]: conn=0 op=1 ADD dn="cn=suzuki,ou=People,dc=example,dc=com"
Feb 16 21:11:11 localhost slapd[4044]: conn=0 op=2 UNBIND
Feb 16 21:11:11 localhost slapd[4044]: conn=0 op=1 RESULT tag=105 err=0 text=
Feb 16 21:11:11 localhost slapd[4044]: conn=0 fd=10 closed
Feb 16 21:11:11 localhost slapd[4044]: conn=1 fd=10 ACCEPT from IP=127.0.0.1:32786 (IP=0.0.0.0:389)
Feb 16 21:11:11 localhost slapd[4044]: conn=1 op=0 BIND dn="cn=Manager,dc=example,dc=com" method=128
Feb 16 21:11:11 localhost slapd[4044]: conn=1 op=0 BIND dn="cn=Manager,dc=example,dc=com" mech=SIMPLE ssf=0
Feb 16 21:11:11 localhost slapd[4044]: conn=1 op=0 RESULT tag=97 err=0 text=
Feb 16 21:11:11 localhost slapd[4044]: conn=1 op=1 SRCH base="dc=example,dc=com" scope=2 deref=0 filter="(cn=suzuki)"
Feb 16 21:11:11 localhost slapd[4044]: conn=1 op=1 SEARCH RESULT tag=101 err=0 nentries=1 text=
Feb 16 21:11:11 localhost slapd[4044]: conn=1 op=2 UNBIND
Feb 16 21:11:11 localhost slapd[4044]: conn=1 fd=10 closed
リスト5 loglevel 128の場合
Feb 16 21:11:18 localhost slapd[4083]: => access_allowed: write access to "ou=People,dc=example,dc=com" "children" requested
Feb 16 21:11:18 localhost slapd[4083]: <= root access granted
Feb 16 21:11:18 localhost slapd[4083]: => access_allowed: write access to "cn=suzuki,ou=People,dc=example,dc=com" "entry" requested
Feb 16 21:11:18 localhost slapd[4083]: <= root access granted
Feb 16 21:11:18 localhost slapd[4083]: => access_allowed: search access to "cn=suzuki,ou=People,dc=example,dc=com" "cn" requested
Feb 16 21:11:18 localhost slapd[4083]: <= root access granted
Feb 16 21:11:18 localhost slapd[4083]: => access_allowed: read access to "cn=suzuki,ou=People,dc=example,dc=com" "entry" requested
Feb 16 21:11:18 localhost slapd[4083]: <= root access granted
Feb 16 21:11:18 localhost slapd[4083]: => access_allowed: read access to "cn=suzuki,ou=People,dc=example,dc=com" "objectClass" requested
Feb 16 21:11:18 localhost slapd[4083]: <= root access granted
Feb 16 21:11:18 localhost slapd[4083]: => access_allowed: read access to "cn=suzuki,ou=People,dc=example,dc=com" "sn" requested
Feb 16 21:11:18 localhost slapd[4083]: <= root access granted
Feb 16 21:11:18 localhost slapd[4083]: => access_allowed: read access to "cn=suzuki,ou=People,dc=example,dc=com" "cn" requested
Feb 16 21:11:18 localhost slapd[4083]: <= root access granted
Feb 16 21:11:18 localhost slapd[4083]: => access_allowed: read access to "cn=suzuki,ou=People,dc=example,dc=com" "mail" requested
Feb 16 21:11:18 localhost slapd[4083]: <= root access granted
リスト6 loglevel 64の場合
Feb 16 21:11:34 localhost slapd[4160]: line 21 (index cn,serviceType,objectClass,uid,uidNumber,gidNumber,memberUid eq)
Feb 16 21:11:34 localhost slapd[4160]: index cn 0x0004
Feb 16 21:11:34 localhost slapd[4160]: index serviceType 0x0004
Feb 16 21:11:34 localhost slapd[4160]: index objectClass 0x0004
Feb 16 21:11:34 localhost slapd[4160]: index uid 0x0004
Feb 16 21:11:34 localhost slapd[4160]: index uidNumber 0x0004
Feb 16 21:11:34 localhost slapd[4160]: index gidNumber 0x0004
Feb 16 21:11:34 localhost slapd[4160]: index memberUid 0x0004
Feb 16 21:11:34 localhost slapd[4160]: line 26 (access to attrs=userPassword by anonymous auth by self write by * none)
Feb 16 21:11:34 localhost slapd[4160]: line 28 (access to * by * read)
リスト7 loglevel 32の場合
Feb 16 21:11:52 localhost slapd[4237]: begin get_filter
Feb 16 21:11:52 localhost slapd[4237]: EQUALITY
Feb 16 21:11:52 localhost slapd[4237]: end get_filter 0
Feb 16 21:11:52 localhost slapd[4237]: => bdb_filter_candidates
Feb 16 21:11:52 localhost slapd[4237]: AND
Feb 16 21:11:52 localhost slapd[4237]: => bdb_list_candidates 0xa0
Feb 16 21:11:52 localhost slapd[4237]: => bdb_filter_candidates
Feb 16 21:11:52 localhost slapd[4237]: OR
Feb 16 21:11:52 localhost slapd[4237]: => bdb_list_candidates 0xa1
Feb 16 21:11:52 localhost slapd[4237]: => bdb_filter_candidates
Feb 16 21:11:52 localhost slapd[4237]: EQUALITY
Feb 16 21:11:52 localhost slapd[4237]: <= bdb_filter_candidates: id=0 first=0 last=0
Feb 16 21:11:52 localhost slapd[4237]: => bdb_filter_candidates
Feb 16 21:11:52 localhost slapd[4237]: EQUALITY
Feb 16 21:11:52 localhost slapd[4237]: <= bdb_filter_candidates: id=1 first=3 last=3
Feb 16 21:11:52 localhost slapd[4237]: <= bdb_list_candidates: id=1 first=3 last=3
Feb 16 21:11:52 localhost slapd[4237]: <= bdb_filter_candidates: id=1 first=3 last=3
Feb 16 21:11:52 localhost slapd[4237]: <= bdb_list_candidates: id=1 first=3 last=3
Feb 16 21:11:52 localhost slapd[4237]: <= bdb_filter_candidates: id=1 first=3 last=3
Feb 16 21:11:52 localhost slapd[4237]: => test_filter
Feb 16 21:11:52 localhost slapd[4237]: EQUALITY
Feb 16 21:11:52 localhost slapd[4237]: <= test_filter 6
これらのサンプルからわかるように,loglevelは適切に設定しておく必要があります。さもなければ,トラブルが起きても全くログが吐かれていなかった,ということにもなりかねません。基本的にはloglevel 256などを設定しておくのが良いでしょう。


