第 7 章 日志文件参考
红帽目录服务器(Directory 服务器)提供日志来帮助监控目录活动。监控有助于快速检测和补救故障,并在主动执行时分析并解决潜在的问题,从而导致性能下降或性能不佳。有效监控目录的一部分是了解日志文件的结构和内容。
本章不提供日志消息的详细列表。但是,本章中提供的信息充当常见问题的良好起点,并更好地了解访问、错误和审计日志中的信息。
日志按目录服务器实例保留,位于 /var/log/dirsrv/slapd-instance
目录中。
7.1. 访问日志参考 复制链接链接已复制到粘贴板!
目录服务器访问日志包含有关到目录的客户端连接的详细信息。连接是来自同一客户端的一系列请求,其结构如下:
- 连接记录,它提供连接索引和客户端的 IP 地址
- 绑定记录
- 绑定结果记录
- 在连接、关闭和带出记录时,操作请求和操作结果对或单个记录序列
- 取消绑定记录
- 关闭记录
以下是访问日志条目示例:
[23/Jun/2020:16:30:27.388006333 -0400] conn=20 op=5 SRCH base="dc=example,dc=com" scope=2 filter="(&(objectClass=top)(objectClass=ldapsubentry)(objectClass=passwordpolicy))" attrs="distinguishedName"
[23/Jun/2020:16:30:27.388006333 -0400] conn=20 op=5 SRCH base="dc=example,dc=com" scope=2 filter="(&(objectClass=top)(objectClass=ldapsubentry)(objectClass=passwordpolicy))" attrs="distinguishedName"
除了单独显示的连接、关闭和带外记录外,所有记录会出现在对中,由服务记录的请求以及 RESULT
记录组成:
[23/Jun/2020:16:30:27.390881301 -0400] conn=20 op=5 RESULT err=0 tag=101 nentries=0 wtime=0.000035342 optime=0.002877749 etime=0.002911121
[23/Jun/2020:16:30:27.390881301 -0400] conn=20 op=5 RESULT err=0 tag=101 nentries=0 wtime=0.000035342 optime=0.002877749 etime=0.002911121
RESULT
消息包含以下与性能相关的条目:
-
wtime
: 在 worker 线程获取操作前操作在工作队列中等待的时间 -
optime
: 执行任务的实际操作所需的时间 -
etime
: 过长的时间,覆盖服务器向客户端发回结果的时间。
wtime
和 optime
值提供有关服务器如何处理负载和进程操作的有用信息。由于目录服务器收集这些统计数据的时间,wtime
和 optime
值的总和比 etime
值稍高。但是,这种非常小的差异是微不足道的。
访问日志有不同的日志记录级别,在 nsslapd-accesslog-level
属性中设置。以下小节提供了默认访问日志记录内容、日志级别以及在不同日志级别记录的内容的概述:
请注意,您无法更改访问日志的格式。
7.1.1. 访问日志记录级别 复制链接链接已复制到粘贴板!
不同的访问日志级别会生成不同数量的详细信息,并记录不同类型的操作。日志级别在实例的 第 3.1.1.2 节 “nsslapd-accesslog-level (Access Log Level)” 配置属性中设置。默认日志级别为 256,它会记录对条目的访问,但有四个不同的日志级别:
- 0 = 无访问日志记录。
- 4 = 用于内部访问操作的日志记录。
- 256 = 用于访问条目的日志记录.
- 512 = 用于访问条目和引用的日志.
这个级别是添加的,因此要启用多种不同类型的日志记录,请将这些级别的值添加到一起。例如,要记录内部访问操作、条目访问和引用,请将 nsslapd-accesslog-level
的值设置为 516
(512
+4
)。
7.1.2. 默认访问日志记录内容 复制链接链接已复制到粘贴板!
本节论述了根据下面显示的默认访问日志级别提取的详情,访问日志内容。
例 7.1. 访问日志示例
连接号
每个外部 LDAP 请求都以增量连接号列出,本例中为 conn=11
,在服务器启动后马上从 conn=0
开始。
[21/Apr/2020:11:39:51 -0700] conn=11 fd=608 slot=608 connection from 207.1.153.51 to 192.18.122.139
[21/Apr/2020:11:39:51 -0700] conn=11 fd=608 slot=608 connection from 207.1.153.51 to 192.18.122.139
默认情况下,内部 LDAP 请求不会记录在访问日志中。要激活内部访问操作的日志记录,在 第 3.1.1.2 节 “nsslapd-accesslog-level (Access Log Level)” 配置属性中指定访问日志级别 4
。
文件描述符
从外部 LDAP 客户端到目录服务器的每个连接都需要操作系统中的文件描述符或套接字描述符,本例中为 fd=608
。fd=608
表示它是使用可用的文件描述符总数的文件描述符编号 608。
[21/Apr/2020:11:39:51 -0700] conn=11 fd=608 slot=608 connection from 207.1.153.51 to 192.18.122.139
[21/Apr/2020:11:39:51 -0700] conn=11 fd=608 slot=608 connection from 207.1.153.51 to 192.18.122.139
插槽号
插槽号在本例中为 slot=608
是访问日志的传统部分,其含义与文件描述符相同。忽略访问日志的这一部分。
[21/Apr/2020:11:39:51 -0700] conn=11 fd=608 slot=608 connection from 207.1.153.51 to 192.18.122.139
[21/Apr/2020:11:39:51 -0700] conn=11 fd=608 slot=608 connection from 207.1.153.51 to 192.18.122.139
操作号
要处理给定的 LDAP 请求,目录服务器将执行所需的一系列操作。对于给定的连接,所有操作请求和操作结果对都会获得以 op=0
开始的增量操作,以识别正在执行的不同操作。
[21/Apr/2020:11:39:51 -0700] conn=11 op=0 RESULT err=0 tag=97 nentries=0 etime=0
[21/Apr/2020:11:39:51 -0700] conn=11 op=0 RESULT err=0 tag=97 nentries=0 etime=0
在 第 7.1.2 节 “默认访问日志记录内容” 中,我们为 bind 操作请求和结果对有 op=0
,然后是 LDAP 搜索请求和结果对的 op=1
,以此类推。访问日志中的条目 op=-1
通常意味着此连接的 LDAP 请求不是由外部 LDAP 客户端发出,而是在内部启动。
方法类型
方法编号在本例中为 method=128
,指示客户端使用了哪些 LDAPv3 绑定方法。
[21/Apr/2020:11:39:51 -0700] conn=11 op=0 BIND dn="cn=Directory Manager" method=128 version=3
[21/Apr/2020:11:39:51 -0700] conn=11 op=0 BIND dn="cn=Directory Manager" method=128 version=3
有三个可能的 bind 方法值:
-
0
用于身份验证 -
128
用于使用用户密码进行简单绑定 -
使用外部身份验证机制的 SASL 绑定的 SASL
版本号
在这种情况下,版本号为 version=3
,表示 LDAP 客户端用来与 LDAP 服务器通信的 LDAP 版本号(LDAPv2 或 LDAPv3)。
[21/Apr/2020:11:39:51 -0700] conn=11 op=0 BIND dn="cn=Directory Manager" method=128 version=3
[21/Apr/2020:11:39:51 -0700] conn=11 op=0 BIND dn="cn=Directory Manager" method=128 version=3
错误号
出错号(本例中为 err=0
)提供了从执行 LDAP 操作返回的 LDAP 结果代码。LDAP 错误编号 0
表示操作成功。有关 LDAP 结果代码的完整列表,请参阅 第 7.4 节 “LDAP 结果码”。
[21/Apr/2020:11:39:51 -0700] conn=11 op=0 RESULT err=0 tag=97 nentries=0 etime=0
[21/Apr/2020:11:39:51 -0700] conn=11 op=0 RESULT err=0 tag=97 nentries=0 etime=0
标签号
标签号在本例中为 tag=97
,表示返回的结果类型,这几乎始终反映所执行的操作类型。使用的标签是来自 LDAP 协议的 BER 标签。
[21/Apr/2020:11:39:51 -0700] conn=11 op=0 RESULT err=0 tag=97 nentries=0 etime=0
[21/Apr/2020:11:39:51 -0700] conn=11 op=0 RESULT err=0 tag=97 nentries=0 etime=0
标签 | 描述 |
---|---|
tag=97 | 客户端绑定操作的结果。 |
tag=100 | 正在搜索的实际条目。 |
tag=101 | 搜索操作的结果。 |
tag=103 | 修改操作的结果。 |
tag=105 | add 操作的结果。 |
tag=107 | 删除操作的结果。 |
tag=109 | moddn 操作的结果。 |
tag=111 | 比较操作的结果。 |
tag=115 | 在执行搜索的条目中包含所需条目的引用时,搜索引用。搜索引用以参考形式表示。 |
tag=120 | 扩展操作的结果。 |
tag=121 | 中间操作的结果。 |
tag=100
和 tag=115
不因此标签,因此它们不太可能记录在访问日志中。
条目数
nentries
显示条目数量,本例中为 nentries=0
,这与 LDAP 客户端的请求匹配。
[21/Apr/2020:11:39:51 -0700] conn=11 op=0 RESULT err=0 tag=97 nentries=0 etime=0
[21/Apr/2020:11:39:51 -0700] conn=11 op=0 RESULT err=0 tag=97 nentries=0 etime=0
已经过的时间
etime
显示经过的时间,在本例中为 etime=3
,或者目录服务器执行 LDAP 操作所需的时间(以秒为单位)。
[21/Apr/2020:11:39:51 -0700] conn=11 op=1 RESULT err=0 tag=101 nentries=1 etime=3 notes=U
[21/Apr/2020:11:39:51 -0700] conn=11 op=1 RESULT err=0 tag=101 nentries=1 etime=3 notes=U
etime
值 0
表示操作实际需要 0 纳秒才能执行。
LDAP 请求类型
LDAP 请求类型指示 LDAP 客户端发布的 LDAP 请求类型。可能的值有:
-
用于搜索的
SRCH
-
用于修改的
MOD
-
DEL
用于删除 -
要添加的
ADD
-
moddn 的
MODDN
-
EXT
用于扩展操作 -
ABANDON
for abandon 操作
如果 LDAP 请求导致对条目进行排序,则会在日志中记录消息 SORT serialno
,后跟排序的候选条目数量。例如:
[04/May/2020:15:51:46 -0700] conn=114 op=68 SORT serialno (1)
[04/May/2020:15:51:46 -0700] conn=114 op=68 SORT serialno (1)
用括号括起的数字指定所排序的候选条目数,本例中为 1
。
LDAP 响应类型
LDAP 响应类型指示 LDAP 客户端发布的 LDAP 响应。有三个可能的值:
-
结果
-
ENTRY
-
REFERRAL
,LDAP 引用或搜索参考
搜索调用器
目录服务器在日志条目的 notes
字段中提供搜索的附加信息。例如:
[21/Apr/2016:11:39:51 -0700] conn=11 op=1 RESULT err=0 tag=101 nentries=1 etime=3 notes=U
[21/Apr/2016:11:39:51 -0700] conn=11 op=1 RESULT err=0 tag=101 nentries=1 etime=3 notes=U
存在以下搜索指示符:
- paged Search Indicator:
notes=P
具有有限资源的 LDAP 客户端可以控制 LDAP 服务器返回搜索操作结果的速率。当执行的搜索使用 LDAP 控制扩展来简单分页搜索结果时,目录服务器会记录
notes=P
paged 搜索指示符。此指示器是信息,不需要进一步的操作。如需了解更多详细信息,请参阅 RFC 2696。
- unindexed Search Indicators:
notes=A
和notes=U
如果没有索引属性,目录服务器必须直接在数据库中搜索它们。这个过程比搜索索引文件更多的资源密集型。
可以记录以下未索引搜索指示符:
notes=A
过滤器中的所有候选属性均未索引,并且需要完整表扫描。这可超过
nsslapd-lookthroughlimit
参数中设置的值。notes=U
在以下情况下设定这个状态:
- 至少一个搜索术语未索引。
在搜索操作过程中达到
nsslapd-idlistscanlimit
参数中设置的限制。详情请查看 第 4.4.1.9 节 “nsslapd-idlistscanlimit”。在以下情况下进行未索引搜索:
-
在用于搜索的索引文件中达到
nsslapd-idlistscanlimit
参数的值。 - 不存在索引文件。
索引文件没有以搜索方式配置。
要优化将来的搜索,请在索引中添加频繁搜索的未索引属性。详情请参阅 Directory Server Administration Guide 中的对应部分。
注意未索引的搜索指示器通常附带一个大的
etime
值,因为未索引的搜索通常更耗时。
除了单个值外,注释
字段可以具有以下值组合: notes=P、A
和 notes=U,P
。
VLV-Related Entries
当搜索涉及虚拟列表视图(VLV)时,会在访问日志文件中记录适当的条目。与其他条目类似,VLV 特定条目可排显示请求和响应信息:
VLV RequestInformation ResponseInformation
VLV RequestInformation ResponseInformation
RequestInformation 的格式如下:
beforeCount:afterCount:index:contentCount
beforeCount:afterCount:index:contentCount
如果客户端使用 position-by-value VLV 请求(第一部分的格式),请求信息将是 beforeCount: afterCount: value。
ResponseInformation 的格式如下:
targetPosition:contentCount (resultCode)
targetPosition:contentCount (resultCode)
以下示例突出显示了特定于 VLV 的条目:
[07/May/2020:11:43:29 -0700] conn=877 op=8530 SRCH base="(ou=People)" scope=2 filter="(uid=*)" [07/May/2020:11:43:29 -0700] conn=877 op=8530 SORT uid [07/May/2020:11:43:29 -0700] conn=877 op=8530 VLV 0:5:0210 10:5397 (0) [07/May/2020:11:43:29 -0700] conn=877 op=8530 RESULT err=0 tag=101 nentries=1 etime=0
[07/May/2020:11:43:29 -0700] conn=877 op=8530 SRCH base="(ou=People)" scope=2 filter="(uid=*)"
[07/May/2020:11:43:29 -0700] conn=877 op=8530 SORT uid
[07/May/2020:11:43:29 -0700] conn=877 op=8530 VLV 0:5:0210 10:5397 (0)
[07/May/2020:11:43:29 -0700] conn=877 op=8530 RESULT err=0 tag=101 nentries=1 etime=0
在上例中,第一部分 0:5:0210
是 VLV 请求信息:
-
beforeCount 为
0。
-
afterCount 为
5
。 -
值为
0210
。
第二部分 10:5397 (0)
是 VLV 响应信息:
-
targetPosition 为
10
。 -
contentCount 为
5397
。 -
(resultCode)是
(0)
。
搜索范围
条目 scope=n
定义执行的搜索范围,而 n
的值为 0
、1
或 2
。
-
0
用于基本搜索 -
1
用于一个级别搜索 -
2
用于子树搜索
扩展操作 OID
例 7.1 “访问日志示例” 中的扩展操作 OID,如 EXT oid="2.16.840.1.113730.3.5.3"
或 EXT oid="2.16.840.1.113730.3.5.5"
,提供了正在执行的扩展操作的 OID。表 7.2 “Directory Server 支持的 LDAPv3 扩展操作” 提供部分 LDAPv3 扩展操作列表及其在目录服务器中支持的 OID。
扩展操作名称 | 描述 | OID |
---|---|---|
目录服务器启动复制请求 | 由复制发起方发送,以指示请求复制会话。 | 2.16.840.1.113730.3.5.3 |
目录服务器复制响应 | 由复制响应器发送以响应 Start Replication Request Extended Operation 或 End Replication Request Extended Operation。 | 2.16.840.1.113730.3.5.4 |
目录服务器结束复制请求 | 发送 以表示要终止复制会话。 | 2.16.840.1.113730.3.5.5 |
目录服务器复制条目请求 |
执行条目及其状态信息( | 2.16.840.1.113730.3.5.6 |
目录服务器 Bulk 导入开始 | 客户端发送请求批量导入以及服务器导入和发送的后缀,以指示可能开始批量导入。 | 2.16.840.1.113730.3.5.7 |
Directory Server Bulk Import Finished | 客户端向客户端发送信号,以表示服务器批量导入和发送的结束以确认它。 | 2.16.840.1.113730.3.5.8 |
更改序列号
更改序列号(本例中为 csn=3b4c8cfb000000030000
)是复制更改序列号,表示此特定命名上下文上启用了复制。
Abandon Message
abandon 消息表示操作已被中止。
[21/Apr/2020:11:39:52 -0700] conn=12 op=2 ABANDON targetop=1 msgid=2 nentries=0 etime=0
[21/Apr/2020:11:39:52 -0700] conn=12 op=2 ABANDON targetop=1 msgid=2 nentries=0 etime=0
nentries=0
表示在操作被中止之前发送的条目数,etime=0
值表示已经经过的时间(以秒为单位),而 targetop=1
对应于之前启动的操作中的操作值(在访问日志中显示)。
根据消息 ID 在查找要中止的操作时,有两个可能的日志 ABANDON
消息。如果消息 ID 成功定位操作( 目标
),则日志将如上所示。但是,如果消息 ID 在查找操作时没有成功,或者在发送 ABANDON
请求之前完成操作,则日志将如下所示:
[21/Apr/2020:11:39:52 -0700] conn=12 op=2 ABANDON targetop=NOTFOUND msgid=2
[21/Apr/2020:11:39:52 -0700] conn=12 op=2 ABANDON targetop=NOTFOUND msgid=2
targetop=NOTFOUND
表示要中止的操作是未知操作或已经完成。
消息 ID
消息 ID (本例中为 msgid=2
)是 LDAP 操作标识符,如 LDAP SDK 客户端生成的。消息 ID 可能与操作号不同的值,但会识别相同的操作。消息 ID 与 ABANDON
操作一起使用,并告知用户被取消的客户端操作。
[21/Apr/2020:11:39:52 -0700] conn=12 op=2 ABANDON targetop=NOTFOUND msgid=2
[21/Apr/2020:11:39:52 -0700] conn=12 op=2 ABANDON targetop=NOTFOUND msgid=2
目录服务器操作号从 0 开始计数,在大多数 LDAP SDK/client 实现中,消息 ID 号从 1 开始计数,这解释了消息 ID 通常等于 Directory Server 操作号加 1。
SASL Multi-Stage Bind Logging
在目录服务器中,多阶段绑定的日志记录是明确的。绑定进程中的每个阶段都会被记录。这些 SASL 连接的错误代码实际上就是返回码。在 例 7.1 “访问日志示例” 中,SASL 绑定正在进行中,其返回码为 err=14
,这意味着连接仍然打开,并且有对应的进度声明 SASL 绑定正在进行
。
[21/Apr/2020:11:39:55 -0700] conn=14 op=0 BIND dn="" method=sasl version=3 mech=DIGEST-MD5 [21/Apr/2020:11:39:55 -0700] conn=14 op=0 RESULT err=14 tag=97 nentries=0 etime=0, SASL bind in progress
[21/Apr/2020:11:39:55 -0700] conn=14 op=0 BIND dn="" method=sasl version=3 mech=DIGEST-MD5
[21/Apr/2020:11:39:55 -0700] conn=14 op=0 RESULT err=14 tag=97 nentries=0 etime=0, SASL bind in progress
在记录 SASL 绑定中,sasl
方法后接 LDAP 版本号 和使用的 SASL 机制,如下面的 GSS-API 机制所示。
[21/Apr/2020:12:57:14 -0700] conn=32 op=0 BIND dn="" method=sasl version=3 mech=GSSAPI
[21/Apr/2020:12:57:14 -0700] conn=32 op=0 BIND dn="" method=sasl version=3 mech=GSSAPI
现在,经过身份验证的 DN (访问控制决策的 DN)记录在 BIND 结果行中,与绑定请求行相反,如之前的情况:
[21/Apr/2020:11:39:55 -0700] conn=14 op=1 RESULT err=0 tag=97 nentries=0 etime=0 dn="uid=jdoe,dc=example,dc=com"
[21/Apr/2020:11:39:55 -0700] conn=14 op=1 RESULT err=0 tag=97 nentries=0 etime=0 dn="uid=jdoe,dc=example,dc=com"
对于 SASL 绑定,服务器不使用绑定请求行中显示的 DN 值,因此不相关。但是,如果经过身份验证的 DN 是 SASL 绑定的 DN,它必须用于审核目的,这非常重要。在绑定结果行中记录这个经过身份验证的 DN 可避免任何混淆。
7.1.3. 访问日志内容以提供额外的访问日志记录级别 复制链接链接已复制到粘贴板!
本节显示在 Directory Server 访问日志中的其他访问日志记录级别。
在 例 7.2 “使用内部访问操作级别访问日志提取(级别 4)” 中,访问启用了日志内部操作的日志记录级别 4
。
例 7.2. 使用内部访问操作级别访问日志提取(级别 4)
[12/Jul/2020:16:45:46 +0200] conn=Internal op=-1 SRCH base="cn=\22dc=example,dc=com\22,cn=mapping tree,cn=config"scope=0 filter="objectclass=nsMappingTree"attrs="nsslapd-referral" options=persistent [12/Jul/2020:16:45:46 +0200] conn=Internal op=-1 RESULT err=0 tag=48 nentries=1etime=0 [12/Jul/2020:16:45:46 +0200] conn=Internal op=-1 SRCH base="cn=\22dc=example,dc=com\22,cn=mapping tree,cn=config"scope=0 filter="objectclass=nsMappingTree" attrs="nsslapd-state" [12/Jul/2020:16:45:46 +0200] conn=Internal op=-1 RESULT err=0 tag=48 nentries=1etime=0
[12/Jul/2020:16:45:46 +0200] conn=Internal op=-1 SRCH base="cn=\22dc=example,dc=com\22,cn=mapping tree,cn=config"scope=0 filter="objectclass=nsMappingTree"attrs="nsslapd-referral" options=persistent
[12/Jul/2020:16:45:46 +0200] conn=Internal op=-1 RESULT err=0 tag=48 nentries=1etime=0
[12/Jul/2020:16:45:46 +0200] conn=Internal op=-1 SRCH base="cn=\22dc=example,dc=com\22,cn=mapping tree,cn=config"scope=0 filter="objectclass=nsMappingTree" attrs="nsslapd-state"
[12/Jul/2020:16:45:46 +0200] conn=Internal op=-1 RESULT err=0 tag=48 nentries=1etime=0
访问日志级别 4
除了正在执行搜索的详情外,还会为内部操作启用日志记录,这些操作会记录搜索基础、范围、过滤器和请求的搜索属性。
在以下示例中,启用了访问日志记录级别 768
(512 + 256),它会记录对条目和引用的访问。在此提取中,会返回六个条目和一个引用以响应搜索请求,该请求显示在第一行中。
连接描述
连接描述(本例中为 conn=Internal
)表示连接是一个内部连接。操作号 op=-1
也表示操作是在内部启动的。
[12/Jul/2020:16:45:46 +0200] conn=Internal op=-1 ENTRY dn="cn=\22dc=example,dc=com\22,cn=mapping tree,cn=config"
[12/Jul/2020:16:45:46 +0200] conn=Internal op=-1 ENTRY dn="cn=\22dc=example,dc=com\22,cn=mapping tree,cn=config"
选项描述
选项描述(options=persistent
)表示正在执行永久搜索,与常规搜索操作区分。永久搜索可用作监控和配置的一种形式,以便在发生更改时返回对给定配置的更改。
本例中同时启用了 512
和 4
日志级别,因此内部访问操作和条目访问和被记录引用。
[12/Jul/2020:16:45:46 +0200] conn=Internal op=-1 SRCH base="cn=\22dc=example,dc=com\22,cn=mapping tree,cn=config"scope=0 filter="objectclass=nsMappingTree"attrs="nsslapd-referral" options=persistent
[12/Jul/2020:16:45:46 +0200] conn=Internal op=-1 SRCH base="cn=\22dc=example,dc=com\22,cn=mapping tree,cn=config"scope=0 filter="objectclass=nsMappingTree"attrs="nsslapd-referral" options=persistent
7.1.4. 常见连接代码 复制链接链接已复制到粘贴板!
连接代码是添加到 关闭日志消息中的代码
,以提供与连接冲突相关的其他信息。
连接代码 | 描述 |
---|---|
A1 | 客户端中止连接。 |
B1 | 损坏的 BER 标签。如果 BER 标签封装在线路上发送的数据,则在收到数据时将损坏,则 B1 连接代码将记录到访问日志中。BER 标签可能会因为物理层网络问题或错误的 LDAP 客户端操作而损坏,如 LDAP 客户端在收到所有请求结果前中止。 |
B2 |
BER 标签大于 |
B3 | 损坏的 BER 标签。 |
B4 | 服务器无法将数据响应刷新回客户端。 |
P2 | 已检测到关闭或损坏连接。 |
T1 |
客户端不会在指定的 |
T2 |
超过 |
U1 | 客户端在客户端发送未绑定请求后由服务器关闭连接。当看到 unbind 请求时,服务器始终关闭连接。 |