3.9. 検索操作ごとの統計情報をログに記録する
検索操作中、特に (cn=user*)
などのフィルターを使用する場合、サーバーがタスクを受信してから結果を送り返すまでにかかる時間 (etime
) が非常に長くなることがあります。
検索操作中に使用されたインデックスに関連する情報によってアクセスログを拡張すると、etime
の値が大きい理由を診断するのに役立ちます。
nsslapd-statlog-level
属性を使用すると、サーバーへの影響を最小限に抑えながら、インデックス検索 (データベース読み取り操作) の数や各検索操作のインデックス検索の全体的な時間などの統計情報を収集できます。
前提条件
- アクセスログを有効にした。
手順
検索操作メトリクスを有効にします。
dsconf -D "cn=Directory Manager" instance_name config replace nsslapd-statlog-level=1
# dsconf -D "cn=Directory Manager" instance_name config replace nsslapd-statlog-level=1
Copy to Clipboard Copied! インスタンスを再起動します。
dsctl instance_name restart
# dsctl instance_name restart
Copy to Clipboard Copied!
検証
検索操作を実行します。
ldapsearch -D "cn=Directory Manager" -H ldap://server.example.com -b "dc=example,dc=com" -s sub -x "cn=user*"
# ldapsearch -D "cn=Directory Manager" -H ldap://server.example.com -b "dc=example,dc=com" -s sub -x "cn=user*"
Copy to Clipboard Copied! アクセスログファイルを表示し、検索統計情報のレコードを見つけます。
cat /var/log/dirsrv/slapd-instance_name/access ... [16/Nov/2022:11:34:11.834135997 +0100] conn=1 op=73 SRCH base="dc=example,dc=com" scope=2 filter="(cn=user)"* attrs=ALL [16/Nov/2022:11:34:11.835750508 +0100] conn=1 op=73 STAT read index: attribute=objectclass key(eq)=referral --> count 0 [16/Nov/2022:11:34:11.836648697 +0100] conn=1 op=73 STAT read index: attribute=cn key(sub)=er_ --> count 25 [16/Nov/2022:11:34:11.837538489 +0100] conn=1 op=73 STAT read index: attribute=cn key(sub)=ser --> count 25 [16/Nov/2022:11:34:11.838814948 +0100] conn=1 op=73 STAT read index: attribute=cn key(sub)=use --> count 25 [16/Nov/2022:11:34:11.841241531 +0100] conn=1 op=73 STAT read index: attribute=cn key(sub)=^us --> count 25 [16/Nov/2022:11:34:11.842230318 +0100] conn=1 op=73 STAT read index: duration 0.000010276 [16/Nov/2022:11:34:11.843185322 +0100] conn=1 op=73 RESULT err=0 tag=101 nentries=24 wtime=0.000078414 optime=0.001614101 etime=0.001690742 ...
# cat /var/log/dirsrv/slapd-instance_name/access ... [16/Nov/2022:11:34:11.834135997 +0100] conn=1 op=73 SRCH base="dc=example,dc=com" scope=2 filter="(cn=user)"* attrs=ALL [16/Nov/2022:11:34:11.835750508 +0100] conn=1 op=73 STAT read index: attribute=objectclass key(eq)=referral --> count 0 [16/Nov/2022:11:34:11.836648697 +0100] conn=1 op=73 STAT read index: attribute=cn key(sub)=er_ --> count 25 [16/Nov/2022:11:34:11.837538489 +0100] conn=1 op=73 STAT read index: attribute=cn key(sub)=ser --> count 25 [16/Nov/2022:11:34:11.838814948 +0100] conn=1 op=73 STAT read index: attribute=cn key(sub)=use --> count 25 [16/Nov/2022:11:34:11.841241531 +0100] conn=1 op=73 STAT read index: attribute=cn key(sub)=^us --> count 25 [16/Nov/2022:11:34:11.842230318 +0100] conn=1 op=73 STAT read index: duration 0.000010276 [16/Nov/2022:11:34:11.843185322 +0100] conn=1 op=73 RESULT err=0 tag=101 nentries=24 wtime=0.000078414 optime=0.001614101 etime=0.001690742 ...
Copy to Clipboard Copied!