Oracle数据库卡顿排查全指南：日志、等待事件与性能分析实战

发布时间：2026/10/14 4:44:09
Oracle数据库卡顿排查全指南：日志、等待事件与性能分析实战
1. 卡顿排查先从日志体系的整体认知开始做Oracle运维的人都知道数据库一卡顿业务方电话打过来第一句话基本都是“库是不是又慢了赶紧看看”。这时候如果漫无目的地开几个查询去瞎猜大概率会浪费宝贵的故障时间。真正有经验的做法是先把数据库的日志体系在心里过一遍知道每一种日志记录了什么、在哪里、怎么快速调取然后才是具体的分析动作。Oracle的日志和诊断文件分布在多个层面大致可以分成这几类告警日志Alert Log、跟踪文件Trace File、监听日志Listener Log、性能统计快照AWR/ASH/STATSPACK、以及操作系统层面的日志。告警日志记录数据库的重大事件、错误和启动关闭过程这是排查卡顿的第一入口跟踪文件则记录某个会话或后台进程的详细活动适合深挖单条SQL或单独进程的问题监听日志负责记录客户端连接请求连接慢或连接风暴的时候就看它AWR和ASH是性能历史档案卡顿结束之后用来复盘、对比、定位性能瓶颈最合适。这里有一个非常重要的认知卡顿不是随机发生的它一定有迹可循。不管是SQL性能恶化、锁等待、I/O瓶颈还是日志切换缓慢、内存竞争都会在相应日志或性能视图里留下线索。排查的本质就是把分散在不同位置的证据串成一条完整的时间线。所以我在处理这类问题时脑子里一直装着一句话先看时间线再找异常最后做根因分析。带着这个思路去看日志效率会高非常多。日志类型默认位置常见环境核心作用卡顿排查价值告警日志 alert_{SID}.log$ORACLE_BASE/diag/rdbms/{dbname}/{SID}/trace/记录错误、启动关闭、参数变更、日志切换定位故障发生时间和错误号跟踪文件 .trc上述同目录或用户指定目录记录会话级详细活动、SQL执行计划、等待事件深挖具体会话卡在哪一步监听日志 listener.log$ORACLE_BASE/diag/tnslsnr/{hostname}/listener/记录连接请求、注册信息排查连接慢、连接数打满的问题AWR 报告数据字典中历史快照保存性能基线数据卡顿前后的指标对比分析ASH 活动会话历史内存及数据字典历史表记录活动会话的采样快照精准定位卡顿时刻的活动SQL归档日志由参数指定目录保存重做日志的历史文件排查归档空间满、日志断档问题这一套日志体系我建议每位DBA都画一张自己环境里的目录树存好。真到故障发生的时候少走一步弯路都是赚的。2. 告警日志定位卡顿的第一战场2.1 告警日志里到底能看到什么告警日志是Oracle数据库的“黑匣子”它按时间顺序记录数据库生命周期里所有关键事件。举几个实际工作中最常见的例子ORA-00600内部错误、ORA-07445进程异常崩溃这类错误出现的时候通常伴随严重的性能问题或进程异常日志切换卡顿和检查点未完成会直接导致数据库瞬间卡死ORA-00060死锁检测到的提示意味着有会话互相持有对方需要的资源形成死循环等待表空间扩展失败、ORA-01653这类错误会造成业务写入直接报错。还有一些参数变更记录、redo日志大小调整、回滚段扩展等操作记录也会在其中留下踪迹。很多人对告警日志有个误区认为它只记录错误。实际上它还会记录很多“看起来正常但实际有问题”的信息。典型的例子是日志切换频繁。有时候告警日志里看不到任何ORA-错误全是正常的日志切换信息但如果切换频率高到每几分钟就切一次重做日志写入的I/O开销会拖慢整个库的性能。这种问题光看错误日志是发现不了的必须结合切换频率来综合判断。查看告警日志最直接的办法是直接找到文件用tail查看最新内容# 进入告警日志目录 cd $ORACLE_BASE/diag/rdbms/orcl/orcl/trace # 查看最新100行 tail -100 alert_orcl.log # 带时间关键字筛选 grep ORA- alert_orcl.log | tail -50在较新版本的Oracle中推荐使用ADRCI命令行工具来查看好处是不用手动找目录、支持按时间过滤adrci show alert -tail 50 adrci show alert -last 36002.2 用“时间线串联法”定位卡顿起点处理过几次生产库卡顿之后我总结了一个特别实用的排查方法自己叫它“时间线串联法”。思路非常简单拿到业务反馈的卡顿时间段之后先去告警日志里把这个时间点前后半小时的所有异常、警告、错误全部捞出来排个序然后再去配合操作系统日志和性能视图验证。具体操作流程大概是这样的。第一步确定故障发生的精确时间这个要问业务最好能精确到分钟级第二步执行如下命令把故障时间前后一定范围内的告警日志内容整体导出# 假设故障窗口是 2025-01-10 14:00 ~ 14:30 awk /2025-01-10 1[34]/ alert_orcl.log /tmp/card_log.txt grep -E ORA-|Errors|Warning|abort|terminated /tmp/card_log.txt第三步把筛出来的内容按时间排序找到最早出现的异常信息这个大概率就是问题的起点。举个例子某次我排查一个卡顿问题业务反馈14点开始系统变慢。我在告警日志里看到14:01有一条ORA-00060死锁记录14:03又出现一条然后每隔几分钟就出现一次。顺着这个线索查下去发现是一个批量更新任务和前台业务程序之间出现循环等待最终锁住了热点表。如果只看业务反馈的时间不去告警日志里抓第一个异常点这问题查起来要绕不少弯路。2.3 实操心得别只盯着ORA-错误看这是我想特别强调的一点。告警日志里经常出现ORA-错误但并不代表所有ORA-错误都值得你处理有些只是“症状”而不是“病根”。举一个真实遇到的例子某次数据库卡顿告警日志里刷了一堆ORA-01653表空间无法扩展看着像磁盘空间不足。但实际查下去才发现真正的原因是某个失控的SQL查询全表扫描把临时表空间撑爆了导致后续写入全部失败。如果盯着表空间扩容去做问题根本解决不了过两天还会再次爆发。我个人的习惯是在告警日志里看到任何ORA-错误都先问三个问题这个错误是什么时候开始出现的它的频率是持续上升还是保持稳定它和业务反馈的卡顿时间段是否吻合只有把这三个问题放进时间线里做交叉验证才能判断它到底是因还是果。另外一个容易忽略的点是检查点相关提示。当数据库出现“Checkpoint not complete”这类信息时意味着日志切换时检查点还没跟上数据库会强制等待这个瞬间的卡顿往往在几百毫秒到几秒之间用户感知非常明显。这类问题在日志里没有红色错误提示只有一行看似普通的警告很多DBA会直接跳过。所以看告警日志尤其是排查卡顿类问题时要养成把“警告级”信息也翻一遍的习惯。3. 跟踪文件与会话级日志拿到第一手现场证据3.1 跟踪文件的价值与分类告警日志能告诉我们“发生了什么”但想知道“具体哪个会话在做什么、为什么慢”就得靠跟踪文件了。跟踪文件在Oracle里分为两类后台进程跟踪文件和用户会话跟踪文件。后台进程跟踪文件记录了DBWR、LGWR、CKPT这些核心后台进程的活动当数据库整体响应变慢时查看这些进程的跟踪文件可以判断是不是某个关键后台进程卡住了。用户会话跟踪文件则记录了具体业务会话的SQL执行细节包括等待事件、解析时间、执行计划等。我一般排查卡顿的逻辑是先用告警日志确定问题的大致方向再用跟踪文件对可疑会话做定点深挖。比如数据库整体不算堵但某一类业务的查询特别慢这种时候定位到具体会话、开启会话跟踪是最直接的。3.2 如何抓取一个正在卡顿的会话的跟踪信息生产环境中我们经常遇到这样的场景业务说某条SQL昨天还很正常今天突然跑不动了。想查原因但SQL执行完就结束了想重跑一遍又怕影响生产。这时候最好的办法是在SQL运行期间直接抓会话的实时等待信息。先找到正在运行的会话信息-- 查看当前有哪些会话正在执行SQL以及它们的等待事件 SELECT s.sid, s.serial#, s.username, s.event, s.wait_time, s.sql_id, s.status, s.blocking_session FROM v$session s WHERE s.type USER AND s.status ACTIVE ORDER BY s.event;这里需要多说两句v$session里几个关键列的含义。event列显示的是当前正在等待的事件如果是“SQL*Net message from client”表示在等客户端发送数据问题在网络或应用层如果是“db file sequential read”表示在做单块读等待通常是索引扫描的I/O瓶颈如果是“enq: TX - row lock contention”则表示在等待行锁释放。blocking_session列如果非空说明这个会话被另一个会话阻塞了顺着这个字段可以一路追到会话源头。定位到急于抓取SQL的会话之后可以用DBMS_MONITOR包对指定会话开启跟踪-- 对指定SID开启SQL跟踪 BEGIN DBMS_MONITOR.SESSION_TRACE_ENABLE( session_id 123, serial_num 456, waits TRUE, binds TRUE ); END; /执行完这条语句后该会话后续执行的SQL、等待事件、绑定变量都会被记录到用户跟踪文件里。等到SQL跑完、业务反馈恢复正常再关闭跟踪BEGIN DBMS_MONITOR.SESSION_TRACE_DISABLE(session_id 123, serial_num 456); END; /然后去USER_DUMP_DEST目录找对应的.trc文件用tkprof工具格式化输出tkprof /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_12345.trc /tmp/trace_report.txt sortprsela,exela,fchela这里要重点说说tkprof排序参数。sortprsela表示按SQL解析耗时排序sortexela表示按执行耗时排序sortfchela表示按数据获取耗时排序。排查卡顿时我最常用的是exela能把最耗时的SQL排在前面。格式化后的报告里会明确列出每个SQL的解析时间、执行时间、获取行数、CPU时间以及占用的比例。3.3 用10046事件做深度诊断有些极端情况数据库不是“慢”而是“卡死”了一样会话在某个事件上等待几十秒甚至几分钟。这种时候常规的v$session查询可能都不太够用需要更细粒度的诊断信息建议用10046事件来做内部诊断。10046事件本质上是Oracle内部跟踪机制按不同level记录不同粒度的信息level 1记录SQL语句文本和解析执行统计level 4在1的基础上增加绑定变量信息level 8记录等待事件level 12则是4和8的组合能拿到最完整的诊断信息这也是我最常用的配置。对当前会话开启10046事件ALTER SESSION SET events 10046 trace name context forever, level 12;然后执行那条有问题的SQL执行完关闭跟踪ALTER SESSION SET events 10046 trace name context off;生成的跟踪文件里会包含每条SQL执行时每一个等待事件的开始时间、持续时长、等待类型。我经常用这个方法来定位某些时快时慢的SQL找出它们在执行计划中具体卡在了哪一步。比如有一次一条关联查询平时跑0.5秒某段时间突然变成10秒用10046看完之后发现不是SQL本身的问题而是它在等某张表的统计数据收集完成后续SQL全部排队。这种情况如果没有10046级别的等待细节很难想象到问题会出在统计信息收集任务上。3.4 实操记录一个完整的会话抓取流程某次模拟项目X的压测环境中业务反映订单查询接口响应时间从正常的200毫秒飙到3秒以上。我按下面的顺序做了排查第一步用上面的v$session查询找出活跃会话发现大量会话的event都是“buffer busy wait”而且集中在某张订单明细表的数据块上第二步通过blocking_session字段顺藤摸瓜找到一个正在做全表更新的大事务会话它就是元凶第三步对这个大事务会话开启10046跟踪确认它更新涉及的行数远超正常业务量第四步结合告警日志发现这个时间段刚好有批量导入任务启动和前台订单写入撞到了一起。整个过程用时大概二十分钟。如果没有跟踪文件给出的等待事件细节仅凭告警日志里的错误信息很难定位到这个层面的问题。4. 性能日志的高级玩法ASH与AWR的实战配合4.1 ASH卡顿发生当时的“行车记录仪”如果说告警日志是黑匣子那ASH就是行车记录仪。它每秒从活跃会话里采样一次记录每个会话当时在执行的SQL、等待的事件、消耗的资源。Oracle把这份数据存在内存里并定期刷到历史表dba_hist_active_sess_history中。这个特性对排查卡顿有一种别的手段无法替代的价值即使当时没有开任何跟踪事后也能还原出那个时间点到底发生了什么。当业务反馈“刚才卡了十分钟现在恢复了”的时候我们完全可以事后去查看那十分钟里所有会话的活动。举例来说-- 查询某时间段内卡顿的活动会话分布 SELECT TO_CHAR(sample_time, HH24:MI:SS) sample_min, session_state, event, COUNT(*) cnt FROM dba_hist_active_sess_history WHERE sample_time BETWEEN TO_DATE(2025-01-10 14:00:00, YYYY-MM-DD HH24:MI:SS) AND TO_DATE(2025-01-10 14:30:00, YYYY-MM-DD HH24:MI:SS) AND dbid (SELECT dbid FROM v$database) GROUP BY TO_CHAR(sample_time, HH24:MI:SS), session_state, event ORDER BY sample_min, cnt DESC;这个查询跑出来的结果能直接展示时间维度上的性能变化曲线。比如14:00到14:05之间几乎所有会话都在等待“enq: TX - row lock contention”那就是锁问题14:05之后等待消失会话恢复运行说明锁已经释放。把采样时间和等待事件一对照问题的轮廓就出来了。再往下追一步定位具体卡顿的SQL-- 找到卡顿时间段内最消耗资源的SQL SELECT sql_id, COUNT(*) cnt, ROUND(COUNT(*) * 100 / SUM(COUNT(*)) OVER (), 2) pct FROM dba_hist_active_sess_history WHERE sample_time BETWEEN TO_DATE(2025-01-10 14:00:00, YYYY-MM-DD HH24:MI:SS) AND TO_DATE(2025-01-10 14:30:00, YYYY-MM-DD HH24:MI:SS) GROUP BY sql_id ORDER BY cnt DESC FETCH FIRST 10 ROWS ONLY;这个结果能告诉我们卡顿期间哪几条SQL占据的会话时间最长。我遇到过不少案例卡顿的根本原因不是SQL本身慢而是某条SQL占用了大量资源把别的SQL挤到一边去等待。ASH的会话采样分布在识别这种“资源抢占型”问题时特别有用。4.2 AWR报告用对比找出性能偏差AWR报告是Oracle自动生成的性能报告默认每小时拍一张快照保存最近7天可配置的统计数据。它的价值不在单张报告本身而在对比。同一套系统和正常时段的性能指标做对比往往能发现卡顿时段的异常指标。生成AWR报告的方式很简单登录SQL*Plus执行?/rdbms/admin/awrrpt.sql按照提示依次选择报告类型HTML或文本、选择起始快照ID、结束快照ID就会生成一份报告。我建议做两个对比一是卡顿时间段的前后快照对比二是卡顿时间段和一周前同一天的正常时段对比。拿到报告后我一般快速扫几个关键指标Top 5 Timed Events区域如果某个等待事件的占比特别高比如超过50%基本就能锁定瓶颈方向SQL Statistics区域里的SQL ordered by Elapsed Time看哪些SQL消耗时间最多Segment Statistics区域观察哪些段被访问异常频繁I/O Stats区域检查物理读、写是否过大。举一个实际案例。某系统的AWR报告显示Top 1等待事件是“log file sync”占比超过70%。所谓log file sync本质上是用户会话提交事务时等待日志写入完成。看到这个指标结合之前从告警日志里看到的频繁日志切换记录我判断问题的核心是磁盘I/O能力跟不上重做日志写入量。后来验证发现重做日志所在的磁盘组同时承载了大量其他业务的写入造成I/O竞争。后面把日志文件单独迁移到独立的存储卷问题直接解决。再看一眼卡顿时间段和正常时间段的I/O对比物理读取量翻了差不多五倍这个数据的指向性已经非常明显了。4.3 从ASH到AWR两层数据互为印证不少新手DBA容易犯一个错误只会用AWR或者只会用ASH两者完全是割裂的。我在实际工作中已经形成一套固定打法先用ASH定位具体时间点的活动会话分布确定问题和哪些SQL、哪些等待事件相关再用AWR报告验证这些等待事件在更长时间跨度上的占比趋势确认问题是偶发还是持续存在。实操中的判断逻辑很简单如果ASH里看到的问题SQL和等待事件在AWR报告的Top事件里占比也很高那说明问题不是抽样偶然而是系统性的性能瓶颈如果ASH里问题很突出但AWR报告整体看起来基本正常那说明问题更偏向短时突发可能是某种临时性锁冲突或并发峰值导致。5. 等待事件连接日志与根因的桥梁5.1 等待事件的基本逻辑Oracle里几乎所有性能问题最终都会表现为某个等待事件。这句话我在各种场合反复念叨因为它确实太重要了。会话在运行SQL时如果不需要等待任何资源那SQL的耗时就是纯CPU时间一旦出现资源争用比如磁盘慢了、锁冲突了、内存不够了会话就会进入等待状态等待事件就记录了它“在等什么”以及“等了多久”。排查卡顿的核心就是把等待事件和业务时间段、日志信息做交叉分析。等待事件分类繁多但对于排查卡顿来说掌握几类最常见的其实就够用了。I/O类等待事件提示磁盘读写慢比如db file sequential read是单块读等待db file scattered read是多块读等待direct path read是在做直接路径读锁等待类提示并发冲突比如enq: TX - row lock contention是行锁等待enq: TM - contention是表锁等待日志提交类反映重做日志写入压力log file sync是提交等待日志落盘此外还有CPU调度类的“CPU used by this session”表示会话本身在消耗CPU而不是在等什么东西。5.2 用等待事件快速判断卡顿性质根据等待事件的分布情况可以把卡顿问题粗分成几种性质然后针对性地去查对应的日志和配置。如果大量会话都集中在I/O类等待上这就是明显的I/O瓶颈型卡顿。这时候要看操作系统的I/O监控工具配合AWR里Tablespace I/O统计和Datafile I/O统计确认是不是特定表空间或数据文件所在的磁盘拖了后腿。再结合告警日志里有没有“log file switch completion”这类日志切换等待可以进一步判断是数据文件慢还是重做日志慢。如果大量会话等待在锁事件上则是并发锁冲突型卡顿。这时候重点查v$lock看是谁持有锁、谁在等锁配合DBA_BLOCKERS和DBA_WAITERS视图定位阻塞链。告警日志如果出现ORA-00060那就是死锁现场的直接证据。如果等待事件以log file sync和log file parallel write为主则是日志写入瓶颈型卡顿。要看日志文件所在磁盘的I/O能力可能需要调大日志文件、增加日志组成员或者把日志迁移到更快的存储上。如果卡顿时段明明跑着一个CPU密集的SQL但等待事件里没有明显等待而是大量CPU used这时要回到SQL执行计划里去分析看看是不是表连接顺序有问题、使用了低效的嵌套循环、或者没有走索引导致大范围扫描。5.3 等待事件排查案例某次一个业务系统在每天晚上8点左右准时变慢业务方多次反馈但一直没找到原因。我查了告警日志前后几天在这个时间段都没有任何错误信息。改用ASH查询之后发现卡顿时段会话的等待事件高度集中在“enq: TX - index contention”上当时就觉得很奇怪因为索引竞争通常意味着大量的并发插入而且都往索引的同一个块上写入这个特征在顺序主键的场景下很典型。顺着这个线索去查每日8点的定时任务发现确实有个批量数据导入的作业在集中插入新一批业务数据而表上的主键索引又恰好是顺序递增的所有会话都去抢索引的同一个叶子块竞争自然就非常激烈。后续把数据导入的时间调整到业务低峰期问题直接消失。如果把这类问题当成普通SQL慢来处理很可能原地打转很久因为SQL本身一点都不慢慢的是它引发的竞争。5.4 一个实用的等待事件速查思路我自己习惯的做法是在排查卡顿时不直接上来就看等待事件的完整列表而是先按时间维度统计等待事件的分布比例让“哪类事件在哪个时间段集中出现”一目了然。下面的查询就是干这个用的SELECT TO_CHAR(sample_time, HH24) hour_bucket, event, COUNT(*) cnt FROM dba_hist_active_sess_history WHERE sample_time SYSDATE - 1 GROUP BY TO_CHAR(sample_time, HH24), event ORDER BY hour_bucket, cnt DESC;这样查完之后我会把数值最突出的几个事件单独拉出来再结合对应的SQL_id做定点分析。整个流程下来问题基本就能锁定到很小的范围内剩下的就是针对性地看执行计划或调整参数了。6. 常见问题与排查技巧实录6.1 排查中常见的陷阱做了这么多年Oracle运维我踩过的坑不少这里挑几个最有代表性的分享出来。第一个坑只查数据库日志不看操作系统层面配合。磁盘空间满了、内存不足、网络抖动这些问题很多时候先在操作系统日志里出现然后才引发数据库异常。我处理过的案例里有两次数据库卡顿最终问题都出在存储交换机故障导致磁盘I/O大面积波动。这种问题光看数据库内部日志容易让人摸不着头脑告警日志里只有I/O错误操作系统日志才真正揭示了存储层的异常。数据库层面和操作系统层面的日志必须一起看交叉验证。第二个坑卡顿已经恢复了才接到反馈没有现场可查。这种时候最忌讳的是直接放弃觉得问题没法查了。ASH历史数据和AWR报告就是为这种场景准备的至少能把可疑SQL和等待事件拉出来复盘。此外如果平时有定期采集AWR并保留历史报告的习惯那排查起来就更从容了。第三个坑错误地依赖单一指标下结论。比如某次看到等待事件以db file sequential read为主直接认定是磁盘I/O慢。结果后来发现磁盘指标完全正常真正的问题是执行计划因为统计信息过期走了错误的索引。等待事件是现象不是根因判断一定要配合执行计划、统计信息、SQL文本综合来看。6.2 常见卡顿问题速查表卡顿表现典型等待事件首先排查位置高频根因整体响应慢磁盘繁忙db file sequential read / scattered readAWR I/O统计、OS磁盘监控磁盘I/O能力不足、SQL低效扫描特定会话卡住不动enq: TX - row lock contentionv$session.blocking_session未提交事务持有行锁频繁提交时报慢log file sync重做日志所在磁盘日志写入I/O慢、磁盘竞争所有会话短时挂起log file switch completion告警日志检查点记录redo日志太小、切换频繁大批量插入时变慢enq: TX - index contention索引顺序和分布索引叶子块热点竞争应用偶发超时SQL*Net message from client监听日志应用服务端异常、网络延迟跑批任务集中时报错ORA-01653表空间使用率表空间不足、段自动扩展失效6.3 几条很有价值的排查心得关于日志的保存和归档我现在的做法是给每套库配置日志轮转策略告警日志、监听日志都做定期归档清理同时把定期生成的AWR报告统一归档保存。这样万一哪天真出了问题历史数据随手就能找到可以对比“正常时”和“出问题时”的差异。没有历史基线很多性能问题根本就没法判断“异常”的边界在哪里。关于日常巡检我强烈建议DBA每周至少看一眼告警日志里最近的ORA-错误哪怕系统运行看起来很稳定。很多卡顿问题的隐患其实早期就会有零星记录比如偶尔的锁超时、偶发的日志切换慢如果当时就深挖一下往往能防患于未然。我自己就有过一次教训某系统出现过几次零星的ORA-00060当时觉得偶发无所谓结果一个月后变成了严重的死锁风暴。从那以后再也不敢忽视任何一条偶发错误了。关于处理优先级我个人的经验是遇到数据库卡顿第一时间先确认有没有锁和阻塞第二时间确认redo日志切换和归档是否正常第三时间才去看SQL性能。这个顺序的依据是锁问题和日志切换问题可能导致的现象最严重有时候会波及全库影响面最大而SQL性能问题通常只影响单个或少数会话影响相对可控。先把能造成“大面积卡顿”的因素排除掉再处理局部问题排查效率会高很多。另外补一个小技巧如果发现某个时间段的ASH数据里活动会话数突然飙高随后断崖式下降这往往暗示数据库在这个时间点经历过一次大范围的阻塞集中释放。这时对比一下阻塞释放前后执行完成的SQL通常能找到那个“被憋了很久然后突然放行”的大事务它就是引发这波卡顿的核心对象。排查Oracle卡顿这件事经验和工具同等重要。工具就摆在那里日志也都在那里差别就在于你是否能在最短时间内定位到对的那一份并在其中找到最关键的证据。