如果不是那天早上打开AWR报告时多看了一眼,我可能到现在都想不到,Oracle 19c的一个安全参数,会成为那台数据库时间消耗的第二大来源。报告里Top 5 Timed Events的第二行,写的是"failed logon delay"——这个等待事件在以往的报告里根本排不上号,甚至很多DBA压根没在AWR里见过它。数据库侧没有明显的慢SQL,Load也谈不上高,但用户就是抱怨登录变慢、批量任务频繁失败,整个DB time被这个事件的累计等待硬生生抬了上去。
这篇就把这次排查的全过程、参数背后的机制、以及最后怎么收场都写出来。如果你负责的19c库也做过安全加固,或者你的应用连库时偶尔冒出一堆登录失败,那这篇大概率能帮上忙。
1. Failed Logon Delay是什么:一个被安全基线悄悄打开的等待事件
1.1 防暴力破解的"冷却时间"从哪来
如果你用一句话概括failed logon delay,它就是Oracle在登录认证环节人为加入的"冷却时间"。出发点很朴素:数据库长期暴露在口令猜测、字典爆破这类风险下,以前主要靠两个参数兜底——FAILED_LOGIN_ATTEMPTS(连续失败几次后锁账号)和PASSWORD_LOCK_TIME(锁多长时间)。这套组合能挡住大部分粗放型爆破,但有个明显的漏洞:攻击者只要把尝试频率压得足够低,每次在账号被锁之前换一批字典继续试,锁账号策略基本就形同虚设。
12c时代Oracle引入了FAILED_LOGON_DELAY。它的思路从"把门锁死"换成了"把敲门的人晾在外面":不管最终成不成功,只要某个账号连续登录失败,下一次对该账号的登录尝试,服务器端就要先等一段时间。这个参数在19c里的默认值是0,也就是默认完全不启用。所以很多人在生产环境里从没见过它——只有当有人显式执行过类似ALTER SYSTEM SET FAILED_LOGON_DELAY=3 SCOPE=BOTH;这种操作后,等待事件才会真实出现。
回到我这次的环境。第一反应就是查当前库里这个参数的值,果然没让人失望,设置为3秒。基本可以断定,是之前某次安全加固时加上的。安全团队的逻辑也完全可以理解:给登录失败加个延迟,防止有人用工具快速探测有效账号,顺便也能缓解一下认证接口被高频调用带来的开销。只是谁也没想到,这个看似合理的3秒,最后会变成几十万秒的数据库时间。
1.2 参数机制里最容易被低估的"递增延迟"
看参数定义的时候,很多人容易忽略一个重要细节:它并不是每次失败后固定等待3秒。同一账号如果连续登录失败,后续的等待时间会按参数值递增。官方文档的描述大致是,每次额外的连续失败都会增加一个延迟周期,最长延迟封顶到3600秒。换句话说,一个账号失败得越频繁,后续每次登录尝试被晾的时间就越长。
这才是它最要命的地方。普通失败一次,等3秒,体感不明显。但一个共享账号反复失败,几轮下来,每次等待可能变成6秒、9秒、12秒……再叠加应用层面的自动重试机制,整个数据库里的server process就会像排队过安检一样,一个接一个地堵在认证环节。
参数的基本信息,整理成一张表方便查阅:
| 项目 | 说明 |
|---|---|
| 参数名 | FAILED_LOGON_DELAY |
| 默认值 | 0(不延迟) |
| 取值范围 | 0 ~ 3600 秒 |
| 生效方式 | 系统级初始化参数,可在线修改 |
| 主要作用 | 账号登录失败后,再次尝试登录前的强制等待 |
| 关联等待事件 | failed logon delay(Wait Class 为 Other) |
1.3 花几分钟在测试环境复现一次
原理讲再多,不如动手看一次。如果你手边有测试库,可以这样复现:创建一个测试账号,把参数设为3秒,然后用错误密码连续登录三次,每次尝试间隙去查一下v$session或者gv$session里对应会话的等待事件,大概率能看到failed logon delay。我一般用这个查询观察:
SELECT sid, serial#, username, program, event, seconds_in_wait, state FROM v$session WHERE username = 'TEST_APP' AND event = 'failed logon delay' ORDER BY seconds_in_wait DESC;很多时候,测试环境跑一遍,对线上问题的理解会比啃半天文档更直观。
2. 现场还原:那天AWR里Top 2的等待事件具体长什么样
2.1 问题表象:登录慢,但SQL没有明显变化
接手这个环境的时候,现象已经很明确:某业务系统的用户反馈,应用登录越来越慢,部分定时批量任务开始频繁报"无法连接数据库"。数据库侧检查了一遍,没有明显的慢SQL变化,系统负载也不算夸张,但数据库时间(DB time)肉眼可见地上了一个台阶。
这种"SQL没事、库却累得不行"的情况,很容易让人一开始就怀疑是主机资源或网络延迟的问题。但看了一眼AWR,问题显然出在数据库自己头上。
2.2 从AWR报告里读出的关键数据
下面是当时其中一个节点报告的核心数据摘录,虽然不是完整表格,但足够说明问题:
| Event | Waits | Time(s) | Avg wait(ms) | % DB Time | Wait Class |
|---|---|---|---|---|---|
| DB CPU | — | 118,430 | — | 44.3 | CPU |
| failed logon delay | 40,287 | 62,480 | 1,551 | 23.4 | Other |
| DB file sequential read | 21,064 | 18,977 | 901 | 7.1 | User I/O |
| db file scattered read | 18,320 | 11,264 | 615 | 4.2 | User I/O |
| enq: TX - row lock contention | 6,302 | 9,310 | 1,477 | 3.5 | Application |
注意看第二行。failed logon delay一共40,287次等待,累计等待时间62,480秒,平均每次等待1.55秒,占整个数据库时间的23.4%。如果是在一个4小时报告区间、两节点RAC的环境里,这个数字已经非常刺眼了。
对比一下前面几个周期的AWR,这个事件基本是零状态。等于说,它是从某个时间点开始突然爆发,然后一直持续到快照结束。当时我心里已经有两个预设判断:第一,一定有一个持续循环的登录失败行为;第二,这些失败请求极大概率全部集中在某一个账号上,否则不会产生如此可观的等待时间。
2.3 最容易犯的误判:以为它只影响客户端
这里有个很多人第一次看到这个事件时都会犯的错误,我也一样。第一反应是:登录失败不是客户端的事吗?密码错了,连接不就立刻断掉了?这种等待怎么会算到数据库头上?
实际上,认证流程本质上是在数据库服务器端执行的。Oracle把这段延迟实现为服务端的定时等待,而不是简单地从客户端把请求拒掉。失败的登录请求到达认证模块后,server process会停留在等待状态,直到延迟结束,才返回认证失败的结果。这个等待过程自然会计入数据库会话的服务时间,于是AWR里就有了它的一席之地。
这也是为什么failed logon delay能占DB time近四分之一的原因——它不是客户端偶尔重试一次的问题,而是数据库端大量进程真的在"睡觉",睡的时间还都算在数据库头上。
3. 机制拆解:3秒的延迟怎么被放大成几十万秒
3.1 数据库时间模型里的"非典型等待"
先补充一个基础概念,方便基础浅一些的朋友理解:Oracle里的DB time,是把所有前台会话消耗的CPU时间和等待时间统一折算出来的一个总量。我们看Top 5 Timed Events,本质上就是在看DB time被哪些东西吃掉了。
比较常见的等待事件,比如DB file sequential read,是索引或单块读遇到I/O等待;enq: TX是行锁竞争。这些事件大家见得多了,判断起来也有经验。但failed logon delay属于Wait Class为Other的那一类,平时在AWR里经常连前五都进不了,大多数人也不会多看它一眼。
它代表的意义很纯粹:一个会话在登录认证阶段,因为前面有连续失败记录而被强制延迟。延迟期间,server process既不读I/O,也不跑CPU,就在那里等定时器触发,时间一到继续认证。这个状态虽然安静,但实实在在占用着会话资源,也贡献着DB time。
3.2 按账号维度叠加:同一个错误账号被反复冲击
这是整个问题的放大器。failed logon delay按数据库账号维度生效,而且账号与账号之间互不影响。不同账号各自有各自的失败计数,失败请求如果分散在100个账号里,每个账号只失败一两次,那产生的等待时间基本可以忽略;但如果1000个失败请求全部集中在同一个账号上,这个账号的延迟时间就会一轮比一轮长,所有请求叠加起来,总时间瞬间爆炸。
我通常用这样一个计算模型来理解:累计等待时间约等于并发失败连接数 × 平均每次等待时间 × 重试轮数。假设某应用配置了一个错误密码的账号,连接池里有30个初始连接,每轮重试都等待3秒起步,失败次数一多,单次等待还会递增到6秒、9秒。30个会话一轮下来就是90秒甚至180秒的DB time,如果这个循环每几分钟来一次,累计到几十万秒也许都不稀奇。
这个模型完美解释了为什么AWR里单次平均等待1.55秒,而不是固定3秒。因为有的会话已经在等待中被采样,有的刚进入等待,有的正处于递增后的第二档延迟,平均值自然会被摊薄。
3.3 最容易引爆这个参数的三种现实场景
回顾这次经验,以下三类场景最容易把failed logon delay送上Top事件榜:
- 连接池配置错误:应用发版后,连接池里保存的数据库密码没有同步更新,服务一重启,所有初始连接全部使用旧密码尝试登录,立刻形成并发失败风暴。
- 批量调度脚本配置过期:某些巡检、报表任务用的数据库账号口令已经变更,但脚本里的连接串还是旧值,定时任务一到点就开始反复撞库。
- 应用探活机制不完善:中间件或监控程序定时做连接探测,但探测用的账号被锁定后一直没有处理,于是每个探测周期都会重新触发一次延迟等待。
再加上Oracle原有的FAILED_LOGIN_ATTEMPTS锁账号策略,账号一旦被锁,后续每次重试依然会进入认证流程,在锁定期内继续叠加延迟等待。防暴破机制和应用重试机制互相叠加,最终把数据库时间推到了高位。
4. 排查链路:从等待事件一路追到具体的连接来源
4.1 第一步:揪出正在等待的会话
拿到AWR报告后,第一件事不是去查参数、看配置,而是先看此时此刻还有多少会话正挂在failed logon delay这个事件上。这样可以最快定位到具体账号和客户端来源。
我用的SQL大致如下:
SELECT inst_id, sid, serial#, username, osuser, machine, program, module, action, seconds_in_wait, state FROM gv$session WHERE event = 'failed logon delay' AND state = 'WAITING' ORDER BY seconds_in_wait DESC;这个查询的关键在于不要限定username,也别只盯当前实例,否则很容易漏掉RAC其他节点上的等待会话。实际执行后,结果非常集中:大量会话的username都是同一个业务账号,machine指向某台应用服务器的IP段,program显示为一个固定的调度模块名。不用再猜,问题账号和来源方向已经锁定了。
4.2 第二步:用监听日志和Alert日志交叉验证
会话信息只能说明"谁在等",还得确认"为什么失败"。这个时候最好用的工具是Oracle的监听日志和数据库Alert日志。
监听日志一般位于$ORACLE_HOME/network/log/listener.log,我习惯用grep直接统计登录失败的记录:
grep -i "ORA-01017\|ORA-28000" listener.log | tail -50可以看到大量来自同一个应用服务器IP的认证失败记录,错误代码基本是ORA-01017(用户名或口令无效)和ORA-28000(账户被锁定)。再配合Alert日志里出现的大量ORA-28000信息,基本就能断定,是那个业务账号的密码配置出了问题,而且账号大概率已经被锁过,之后应用每次重试都在持续撞枪口。
4.3 第三步:用统一审计日志看失败趋势
如果库上开了统一审计,还能用下面这种查询,把失败登录的来源、程序、账号汇总得更清楚,方便写后续报告:
SELECT dbusername, os_username, userhost, program, return_code, COUNT(*) AS fail_cnt FROM unified_audit_trail WHERE action_name = 'LOGON' AND return_code IN (1017, 28000) AND event_timestamp >= TIMESTAMP '2024-06-01 00:00:00' GROUP BY dbusername, os_username, userhost, program, return_code ORDER BY fail_cnt DESC;当时查出来的数据,和v$session里的结论完全对得上:所有失败集中在同一个库账号、同一批应用服务器进程上。到这里,问题的责任方已经从数据库侧转移到了应用配置侧。
4.4 顺藤摸瓜后看到的真相
最后跟业务开发团队确认,原因其实很简单:该业务系统在一次发版时更新了数据库连接串,但密码字段填的还是上一个环境的值。应用重启后,连接池建立初始连接时全部失败,失败后连接池默认还会重试,于是形成了一个循环。
整个链条是:
- 应用使用错误密码尝试连接。
- 数据库账号因为失败次数触发锁定策略,被锁。
- 连接池继续重试,每轮尝试都因failed logon delay被强制等待。
- 等待时间全部计入DB time,AWR里failed logon delay冲到Top 2。
- 应用侧表现为登录慢、连接超时,业务功能异常。
同样的问题,如果发生在没有设置FAILED_LOGON_DELAY的数据库上,可能只是一堆认证失败日志,数据库时间不会有太大变化。但安全参数被打开之后,小问题就被放大成了全局性能事件。
5. 解决路径:怎么在保住安全底线的同时快速止血
5.1 第一步:先截断错误来源,再清掉存量等待会话
发现问题来源后,最快有效的一步是先停掉对应应用侧的连接池或调度任务,阻断新的失败登录注入。如果业务不能随便停,至少要把应用服务器到数据库的网络来源临时限制一下,避免持续撞击。
接着处理已经挂在库里的等待会话。对于这些卡在failed logon delay上的会话,如果确认没有业务价值,可以直接清理:
ALTER SYSTEM KILL SESSION '123,45678,@1' IMMEDIATE;等客户端停止重试后,这个等待事件的新增量会迅速归零。这一步我建议专人盯一下,因为应用重试机制可能在停掉的瞬间又拉起来一批新会话,需要反复确认几轮。
5.2 第二步:修连接配置,解锁账号,重启应用
根因还是应用侧的账密配置。和开发团队确认后,把连接串里的密码改回正确的值,解锁被锁账号:
ALTER USER app_svc IDENTIFIED BY new_password ACCOUNT UNLOCK;然后重启应用,连接池建立新连接时走的就是正确密码,登录失败循环自然终止。这里有个细节:密码更新之后,最好同时清理掉数据库端遗留的失败计数相关状态,因为账号的连续失败历史已经触发延迟递增,即使密码改了,同一个账号短时间内再次登录可能还会被延迟。最简单的方式是等延迟周期自然过期,或者用账号登录一次成功后让计数清零。
5.3 第三步:把参数调整到一个既能防暴破又不误伤的值
参数该不该改回0?我不建议在没有整体评估的情况下直接归零。安全团队加这个参数不是拍脑袋,确实能挡住一部分暴力破解。但3秒加上递增机制,对应用的重试场景来说太敏感了。
与安全团队协商后,我们把参数从3秒调整到1秒,同时要求应用侧必须加连接失败退避机制,不能无间隔重试。调整命令很简单:
ALTER SYSTEM SET FAILED_LOGON_DELAY=1 SCOPE=BOTH;如果想彻底关闭这个延迟,把值改成0即可。但你要清楚,关闭后在防暴力破解维度会少一道缓冲,需要靠网络层访问控制、审计告警来补位。如果库里有多套业务共用一个实例,参数是全局生效的,调低之后原本依赖这个延迟做访问控制的场景也需要重新评估。
5.4 第四步:把一线监控补上,别再等AWR出来才发现
这个问题的可怕之处在于,AWR报告往往是事后复盘才看到,真正的故障窗口早就过去了。我更推荐在运维监控里加一组针对该等待事件的查询,每隔几分钟检查一次累计等待量的增幅:
sqlplus -S / as sysdba <<'EOF' set pages 0 lines 200 col event format a30 col wait_class format a15 SELECT event, total_waits, ROUND(time_waited_micro/1000000, 2) AS time_sec, wait_class FROM gv$session_event WHERE event = 'failed logon delay' AND total_waits > 0 ORDER BY time_waited_micro DESC; EOF如果看到同一节点上这个事件的总等待量在一个小时内明显跳增,就要赶紧追查登录失败来源。把这个指标纳入值班巡检列表,以后类似的坑大概率能在AWR Top 2之前就被扼杀。
5.5 应用侧的长效整改
这次事件的根子,其实是密码管理和变更流程的问题。数据库账密一改,连接池配置没跟上,立刻就会引爆类似问题。后续我推动做了三件事:
- 所有应用连接串统一走配置中心管理,口令变更时生成新版本,并强制重新发布应用配置,而不是让开发手工改文件。
- 中间件连接池开启连接测试SQL,避免拿一个已经失效的连接去做业务请求;失败重试加入指数退避,不要一失败就密集重连。
- 数据库侧对于共享账号的登录失败监控单独建告警,任何账号一小时内的失败次数超过阈值就通知值班人员。
这套组合下来,之后再发生账密不一致的问题,影响面会小很多,也不会再让一个3秒的冷却时间吃掉整个库的数据库时间。
6. 这次踩坑之后,我对安全参数的新认识
说句实在话,以前做安全加固,我更多关注的是"参数有没有配上",很少去追究它在一个真实业务系统里会被怎么放大。FAILED_LOGON_DELAY这个事件让我彻底改了习惯:凡是涉及连接认证类的安全参数,上线前必须和业务团队一起过一遍,至少确认三件事——当前所有连接串的账号口令是否正确、应用失败重试机制是怎样的、出问题时的告警能否第一时间定位到具体客户端。
现在每次到一个新的Oracle 19c环境,我都会第一时间查这个参数的值,并且把failed logon delay加进日常等待事件的观察清单。哪怕它是AWR里的一个生面孔,只要出现在Top 5,基本都意味着有人在用错误的方式反复撞击数据库登录入口。这种问题不是数据库性能调优能解决的,它更像是一个连接管理和账号配置的卫生问题,查清楚了,改到位了,数据库时间自然就降下来了。