前一阵给某客户的业务系统做19c升级后的例行巡检,拉AWR报告时看到一个让人意外的场面:Top 10 Foreground Wait Events里,第二名不是常见的db file sequential read,也不是log file sync,而是Failed Logon Delay。这个等待事件平时在报告里基本是陪跑角色,这次居然排到了DB CPU后面,总等待时间远超其他I/O类事件。第一反应是报告导错了或者快照区间选歪了,重新拉了一次,结果依旧。于是整个排查过程从"这是什么事件"开始,一路查到了应用连接池的密码配置上。
这篇文章把这次排查的完整思路和解决过程整理出来。如果你正在用19c,或者刚做完11g到19c的升级,又恰好发现AWR里这个事件莫名冒头,这篇文章应该能帮你少走不少弯路。
1. 这个等待事件到底在等什么
1.1 "失败登录延迟"是数据库的安全策略
Failed Logon Delay,官方归类为Other等待类,本质上是Oracle在登录失败后强制执行的一次短休眠。休眠时间默认约1秒,目的是让暴力猜密码的尝试自动降速。假设攻击者每秒可以发起上百次认证请求,每一次失败都强制睡1秒,实际的猜测效率就会被压到每秒一次左右,等于给暴力破解踩了一脚刹车。
这个策略的实现位置在数据库的认证环节。用户名密码校验失败后,会话不会立刻把错误返回给客户端,而是先进入一次可控的等待,等待结束才返回类似ORA-01017这样的错误。这个过程中会话既不消耗CPU也不做I/O,就是在纯等。也正因为如此,它非常隐蔽,系统负载看起来不高,但应用侧的连接请求却在排队。
1.2 为什么19c里更容易暴露出来
很多从11g升级上来的环境会对这个事件格外敏感。早期版本的安全模型更宽松,只有连续失败达到一定次数后才会触发延迟;而19c的安全基线明显上调,登录失败后的强制延迟变得更"勤快",几乎每次失败都会被记上一笔。
再加上19c默认启用统一审计,登录失败的记录更完整,AWR里相关等待事件的统计也就更显眼。本身是安全机制,但一旦应用配置出了问题,它就会从"无声保护者"变成占据Top等待事件榜单的"隐形杀手"。排查时的关键认知是:看到Failed Logon Delay排前几名,不要急着怀疑数据库性能,先想想是不是有人在反复登录失败。
2. 现场现象:业务没挂但应用连接大量超时
2.1 AWR快照里的真实数据
这次客户环境的快照窗口是晚上18:00到18:30,半小时的实际运行时间只有1800秒,但AWR里Failed Logon Delay的累计等待时间超过了8000秒。这个数字乍一看很反常,因为一个半小时窗口不可能有超过1800秒的"累计"等待。其实AWR统计的是所有会话等待时间的总和,多个会话并行等待时,总量自然会超过墙钟时间。
当时Top事件的大致分布是:
| 事件 | Total Wait Time (秒) | 说明 |
|---|---|---|
| DB CPU | 约8600 | CPU消耗 |
| Failed Logon Delay | 约8100 | 登录失败等待 |
| db file sequential read | 约2300 | 单块读 |
| log file sync | 约1100 | 提交等待 |
Failed Logon Delay的数量级已经和DB CPU平起平坐。换算一下,相当于这半小时里平均有4到5个会话一直在"罚站"。从数据库全局看,这个并发度并不高,但它每罚站一次就是完整的1秒,于是等待时间迅速堆积,直接冲进Top 3。
2.2 业务侧和数据库侧的巨大反差
奇怪的是,数据库主机的CPU、内存和I/O指标都很平稳,没有明显的资源瓶颈。但业务侧却出现了偶发连接超时,应用日志里能看到一批ORA-01017(用户名或口令无效)和ORA-28000(账户被锁定)。刚开始对接的应用团队以为是数据库"卡了",催着查性能问题。实际上数据库一点都不卡,真正的问题是有大量连接在认证环节反复失败,每次失败都要睡1秒,应用等不起,连接就超时了。
这种反差是Failed Logon Delay排Top事件时最容易误导人的地方。如果只盯着资源使用率,根本定位不到问题;必须意识到,登录失败本身也是一种负载。而且它比普通SQL更麻烦,因为普通SQL最多慢几毫秒,登录失败是实打实的秒级等待,对用户侧感知来说非常致命。
3. 定位思路:从日志到应用,三步锁定元凶
3.1 第一步:用系统视图量化失败登录规模
排查的第一步不是直接翻应用配置,而是先确认等待事件确实没有被误领。可以从v$system_event里看当前累计值:
SELECT event, total_waits, time_waited_micro / 1000000 AS time_waited_sec FROM v$system_event WHERE event = 'Failed Logon Delay';如果这个值在很短时间内快速增加,说明系统正在持续产生失败登录,而不是某个瞬间的偶发。如果增长缓慢,那多半是历史残留,可以继续观察。当时执行两次查询间隔1分钟,total_waits涨了几百,基本确认当前仍有大量认证失败在发生。
3.2 第二步:翻Alert日志和监听日志
确认存在持续失败后,开始查来源。第一步看数据库Alert日志:
grep -i "ORA-01017\|ORA-28000\|ORA-28001" $ORACLE_BASE/diag/rdbms/*/*/trace/alert_*.logAlert日志里能看到账户被锁定的记录,但失败登录本身不一定会写进Alert日志,所以还要去监听日志里找线索。监听日志位于$ORACLE_HOME/network/log/listener.log,重点搜登录失败相关的标记:
grep -i "login failed\|authentication failed\|ORA-1017" listener.log监听日志里能拿到客户端IP、端口和连接的服务名。当时很快看到大量来自同一应用服务器网段的连接失败记录,方向基本明确:问题出在某个应用,不是外部扫描,也不是数据库自身。
3.3 第三步:用统一审计查清来源
19c默认开启统一审计,这对定位非常有利。如果当前用户有AUDIT权限,可以直接查统一审计视图,把失败登录按来源维度聚合:
SELECT os_username, userhost, dbusername, terminal, returncode, COUNT(*) FROM unified_audit_trail WHERE action_name = 'LOGON' AND returncode IN (1017, 28000, 28001) AND event_timestamp >= SYSDATE - 1 GROUP BY os_username, userhost, dbusername, terminal, returncode ORDER BY COUNT(*) DESC;如果统一审计没有记录,可以临时开启登录审计策略,但生产环境操作审计策略需要谨慎评估。总之,这一步的目的只有一个:回答"是谁在登录失败"。当时结果非常集中,某个业务账号的失败量占了九成以上,来源主机指向一台承担交易查询的应用服务器。
3.4 应用侧核实:连接池密码和客户端版本
数据库侧的定位已经足够明确,接下来就是到应用服务器上核实。查了该中间件的连接池配置,发现数据源里使用的账号密码早已不是当前数据库里的值。数据库侧密码近期做过周期变更,连接池没同步更新,应用连一次失败一次。更麻烦的是,连接池里配置了大量初始化连接,每一次失败都要经历完整的认证流程,数据库侧就会产生大量Failed Logon Delay等待。
这里还有个容易遗漏的点,就是客户端版本兼容性。某些老旧的JDBC或OCI客户端在连接19c时可能因认证协议不匹配直接失败,表面上也是登录失败,但这种失败多半不会进入Failed Logon Delay等待。所以排查时别把两种现象混在一起,协议不匹配通常报ORA-28040,连接池密码错误通常报ORA-01017,错误码能帮我们快速分流。
4. 解决路径:先止血,再根治
4.1 临时止血:确认元凶后修正连接配置
定位到数据源密码不一致后,我们让应用团队先在测试连接串上改了密码,验证登录成功,再正式更新连接池配置并重启应用。这个动作生效非常快,几十秒后监控里Failed Logon Delay的增量就断了,AWR里这盏红灯慢慢熄灭。整个过程没有重启数据库,也没改任何数据库参数。
如果当时应用团队无法立刻更新配置,也可以先用数据库侧手段暂时降压。比如用隐藏事件关闭登录延迟,但这个方法只建议在测试环境或明确可控的应急窗口使用,因为绕过安全机制的代价可能不是马上显现,而是会在下一次安全审计时找上门:
ALTER SYSTEM SET EVENT='28401 TRACE NAME CONTEXT FOREVER, LEVEL 1' SCOPE=SPFILE;这个改动需要重启实例才能生效。用之前务必记录变更原因和时间,事后及时清理。
4.2 安全机制与性能的取舍:要不要关闭延迟
网上有很多帖子讨论如何调短或关闭这个延迟,但我的建议是:不要因为一次配置事故就否定安全机制。Failed Logon Delay本质上是在帮你防暴力破解,如果因为应用配错密码就把它关掉,等于为了一个临时问题削弱长期安全底座。更稳妥的做法是保留默认延迟,把精力花在根因治理上。
那什么时候才考虑调?如果系统里存在大量外部应用,口令配置管理又长期混乱,无法短时间内收敛,可以评估在防火墙或连接层做前置控制,而不是直接关审计。比如把暴露面缩小,减少无效来源IP的访问权限。这比改数据库内部行为更安全、更合规。
4.3 长期处置:连接池配置和账号周期变更
这类问题的根源常常不是数据库,而是账号生命周期管理。密码定期更换是好事,但连接池配置、脚本里的硬编码密码、数据源初始化参数都要同步更新。建议的做法是:
- 建立密码变更的运维日历,变更窗口内明确通知所有关联应用。
- 应用侧把密码集中到配置中心管理,避免散落在代码或XML文件里。
- 连接池开启连接有效性校验,比如JDBC连接池配置testOnBorrow或等价参数,让失效连接在复用前被识别出来。
- 定期检查统一审计视图,把登录失败TOP来源纳入日常巡检报表。
任何一条漏了,都可能在某次密码轮换后,让Failed Logon Delay悄无声息地冲进AWR Top榜单。
5. 实战避坑:常见问题和排查速查
5.1 为何我关掉延迟后业务依然超时
有人以为关闭Failed Logon Delay业务就会立刻恢复,其实未必。如果失败的根因没解决,连接池里的请求依然会持续失败,只是不再有1秒等待,但应用需要重新发起连接请求,同样会造成延迟。当时我们只把event 28401作为一种临时止血手段,真正的恢复点在应用侧配置修正。先降噪,再挖根因,顺序不能反。
5.2 如何区分暴力破解与应用误配置
区分方法主要看来源和规律。暴力破解通常是陌生IP扫描、单个账号低成功率、目标分散;应用误配置通常集中在固定来源IP、固定业务账号、失败模式非常规律。查询时可以直接按userhost和dbusername分组统计,如果来源集中且账号单一,基本可以排除外部攻击。
5.3 19c升级后的客户端兼容性陷阱
升级到19c后还要检查客户端的数据库驱动版本。老版本驱动可能走旧的认证协议,升级后第一次连接就开始报错,错误码往往不是密码错误,而是协议不匹配。这类连接失败如果要解除,通常需要升级驱动或调整SQLNET认证参数。但这个方向容易和Failed Logon Delay混淆,判断标准是看Waiting事件是否真的出现:密码错误引发的认证失败会先进入延迟等待,协议不匹配则基本走不到延迟环节。下次如果AWR里这个事件暴增但密码检查又没问题,就要往驱动版本上想。
5.4 速查表
| 现象 | 优先排查方向 | 常用手段 |
|---|---|---|
| Failed Logon Delay总量快速上涨 | 连接池密码过期、账户锁定 | 统一审计按来源计数 |
| 固定账号大量ORA-01017 | 应用数据源配置错误 | 核对应用配置、修改密码 |
| 大量ORA-28000 | 密码策略触发锁定 | 检查PROFILE、解锁操作需谨慎 |
| 升级后出现ORA-28040 | JDBC/OCI驱动版本过旧 | 升级驱动或调整认证参数 |
| 应用连接超时但数据库CPU很低 | 登录失败等待堆积 | 观察Top Event和登录失败统计 |
| 关闭延迟后仍超时 | 根因未解决或连接池已耗尽 | 优先修应用,而不是继续调数据库 |
这次排查下来,我个人最大的感触是:数据库里很多"怪现象"其实并不怪,只是平时关注点都放在SQL和IO上,忽略了登录链路本身也是用户感知的一部分。Failed Logon Delay排到Top 2,本质上不是数据库变慢,而是身份认证这条门禁通道出了问题。以后再看到这个事件冒尖,我的习惯是先问一句:谁的密码又没同步?整理这篇文章,也是想给同样踩坑的同行留个参照,少绕点弯路。