2.3 数据库日常案例精析

对于普通故障,我们可以根据“ORA-”的报错信息或其他明显的错误信息判断出问题的方向,根据以往的经验或MOS(My Oracle Support)找到对应的解决办法。而对于疑难杂症,首先需要了解问题的症状,有辨别地听取描述,尽可能多地获取一手信息,其次是对问题进行分类,有针对性地获取日志信息,并进行分析。接下来,笔者将以具体案例的形式,为大家详细解析。

2.3.1 存储链路引起的性能问题

某社保客户通过RAC双活架构,将底层的存储分别放置在同城的不同机房中,中间通过裸光纤连接。某次因城市基建而导致光纤被挖断。光纤挖断修复期间,数据库没有做任何更改,但在这种情况下,几乎每个周末的上午异地医保刷卡业务频繁出现卡顿延迟现象。期间也寻求过其他乙方,但最终未果,由于影响到正常业务且涉及面较大,该客户希望我们给予帮助。笔者接手并了解了大致情况之后,从中间件开始排查,以下是具体的排查诊断过程。

从tuxedo中间件日志(图2-6)中我们可以看出,8点28分出现了空间不足的问题,进程派发超时,最后tuxedo通过自重启临时解决,重启过程暂时不可用,这与异地刷卡出现卡顿的故障现象相吻合。

图2-6 tuxedo中间件日志

首先,笔者通过优化tuxedo参数,排除了中间件的问题,具体修改如下。

修改/tuxedo/appdir目录下tuxedo配置文件ubbqzsi_lix中的四个参数,具体如下:


MAXACCESSERS   当前值  150   目标值  650
MAXSERVERS     当前值  150   目标值  450
MAXSERVICES    当前值  150   目标值  450
MAXWSCLIENTS   当前值  50    目标值  150

上述代码段中四个参数的说明具体如下。

·MAXACCESSERS:表示在某一个MACHINE上可以并发访问bulletin board(BB)的客户端和服务进程的总和。

·MAXSERVERS:用于限制可以启动的服务总数。

·MAXSERVICES:用于限制可以发布的交易总数。

·MAXWSCLIENTS:表示最多可以有多少个远程客户端同时连接。

MAXACCESSERS、MAXSERVERS、MAXSERVICES这三个参数控制了该tuxedo应用系统对IPC(进程的通信)资源的使用情况。

修改tuxedo部分参数后,业务中断的现象就不再出现了,但是周末及周一业务高峰期卡顿延迟的现象并没有得到彻底解决,以上现象说明修改参数只能临时加大tuxedo允许的延迟时间及处理进程的时间,但这并没有从根本上解决问题。

图2-7所示的是tuxedo日志的部分截图,从中我们可以看出,7点19分出现了一次服务进程超时的问题,tuxedo通过自重启来临时解决该问题。从报错信息可以得知,业务处理时间相比以往有所变长,超过了tuxedo配置超时时间40秒,因此进程被终止。

图2-7 tuxedo中间件日志

根据日志信息继续分析,可以得出进程超时,是由于数据库处理时间过长而导致的,为了明确这个结论,我们继续查看数据库当时的运行状态,如图2-8所示。

图2-8 数据库等待事件

图2-9所示的是数据库性能分析报告中正常时间段的截图。

图2-9 正常时间段数据库性能报告截图

图2-10所示的是数据库性能分析报告中故障时间段的截图。

图2-10 故障时间段数据库性能报告截图

图2-11所示的是故障时间段操作系统资源使用情况的截图。

最后,确认数据库盘符的使用情况,如图2-12所示。

图2-11 操作系统资源使用情况截图

图2-12 数据库盘符使用情况

结合数据库及操作系统资源的使用情况,我们可以得知,在故障时间段,数据库一直处于繁忙状态。从数据库等待事件及性能分析报告中,我们可以得知,高峰时间段数据库正在进行备份操作,消耗了大量的I/O资源,操作系统的磁盘使用率也非常高,CPU出现了部分I/O等待。

与NBU备份厂商沟通之后,我们发现,备份时间从原来的3小时延长至8小时,有大I/O需求(如备份或周一高峰期)时,这种延时现象就会出现。而低谷期I/O需求量较低的时候,数据库的整体性能表现还是比较正常的。

从以上种种现象我们基本可以判定,故障时间段操作系统I/O的响应已经无法满足当前数据库的需求,导致数据库出现了严重的I/O等待,从而间接影响了NBU备份的时间。

为了证明这一点,我们详细查看了数据库的I/O性能指标,具体情况如下。

数据库性能报告中,正常时间段的I/O响应情况如图2-13所示。

图2-13 正常时间段的I/O响应情况截图

数据库性能报告中,故障时间段I/O响应情况如图2-14所示。

图2-14 故障时间段的I/O响应情况截图

正常情况下,数据库对I/O响应的时间限制在10毫秒之内,而在故障时间段,数据库I/O性能指标则远远超过了该值,结合之前操作系统磁盘使用率接近100%的情况,整个I/O的读速率只在39~80MB/s之间,速率下降异常明显。

我们还通过dd命令及磁盘文件复制对I/O的性能做了进一步的测试,发现磁盘I/O的读速率只有50~80MB/s,是原来的四分之一,此时已经可以断定存在异常的地方可能是主机到存储的链路或存储本身。

经过一系列的排查,最终定位为同城存储互联的光纤链路存在异常,更换光纤链路后,各个指标恢复了正常,NBU备份时间也恢复到了原来的3小时。

2.3.2 操作系统内存泄漏的案例

某医院客户将P550服务器切换至P720服务器,切换完成之后,数据库版本保持不变,主机操作系统版本从原来的AIX 6.1升级至AIX 7.1(操作系统版本为7100-03-00-0000,没有安装SP3补丁)。运行3天之后,数据库由于操作系统内存不足产生了大量交换,从而导致多次宕机。

P720服务器的内存配置(64GB)比原P550服务器的内存配置(16GB)高。正常情况下,内存不应该存在瓶颈。但故障发生期间,内存使用率高达96%,这种现象是极不正常的。故障期间topas监控工具显示操作系统的资源使用情况如图2-15所示。

图2-15 操作系统资源使用情况

同样,如图2-16所示,vmstat监控命令也显示在故障期间,主机已经产生了大量的交换,内存严重不足。

图2-17所示的是正常时间段的AWR报告。

图2-18所示的是故障时间段的AWR报告。

图2-16 内存使用情况

图2-17 正常时间段的AWR报告

图2-18 故障时间段的AWR报告

对比两份AWR报告我们可以发现,故障时间段的latch:shared pool和libaray cache:mutex x等待十分严重,结合操作系统的资源使用情况,基本上可以确定是由于内存不足而导致的数据库性能急剧下降。

第一次调整参考了图2-19所示的MOS文档:11gR2/Aix-Dedicated Server Processes Have Large Usla Heap Segment Compared To Older Versions(文档ID:1260095.1)。

图2-19 MOS官方文档说明

从Oracle官方提示的文档中我们可以看出,由于USLA HEAP的使用量存在异常,导致内存使用率不断上升。图2-20所示的是本机故障时间段USLA HEAP的使用情况截图。

图2-20 故障时间段USLA HEAP的使用情况

从USLA HEAP的使用情况(1638 4KB pages也就是6.5MB)我们可以判断,进程私有使用量已经接近Oracle官方提示的1800 4KB pages(也就是7MB左右)。这是Oracle官方公布的一个Bug 10190759,解决方法是安装Oracle Patch:10190759补丁,打完补丁之后,USLA HEAP的使用量已经得到了控制,如图2-21所示。

打完补丁之后,数据库的性能稍微有所缓解,但是内存使用率还是偏高,还是有交换出现,如图2-22所示,高峰时间段依然会出现卡死的现象,看来问题并没有得到彻底解决。

图2-21 打补丁后USLA HEAP的使用情况

图2-22 操作系统资源使用情况

数据库SGA配置了16GB,PGA使用了2.4GB,主机内存为64GB,正常情况下,内存使用率不应该会有这么高,正常的使用率应该在百分之六十左右,这可能是由于操作系统的内存没有得到及时释放,从而导致内存的使用量一直在上升。MOS文档Virtual Memory Consumption / Paging under AIX 7.1(文档ID:1666458.1)说明如图2-23所示。

根据Oracle官方提示,由于AIX7.1上的一个Bug,导致进程“clnt text data BSS heap”的内存堆使用量出现了异常。图2-24所示的是本机进程“clnt text data BSS heap”的使用情况。

图2-23 官方文档说明

图2-24 clnt text data BSS heap使用情况

如图2-24中框选处所示,“clnt text data BSS heap”的值为69 132(*4KB,也就是270MB)且还在持续增加,这是极不正常的。检查之后我们发现操作系统没有安装补丁IV53587,检查结果如图2-25所示。

图2-25 操作系统补丁检查

打完相关补丁之后,topas观察相关主机的资源使用情况(见图2-26),从目前的情况看,打了补丁的效果还是比较理想的,内存使用率和“clnt text data BSS heap”都在合理范围之内,如图2-27所示。

图2-26 操作系统资源使用情况

图2-27 打完补丁之后,“clnt text data BSS heap”的使用情况

AIX中进程使用的内存主要分为两个部分:用户数据和程序段。

用户数据主要包含变量、动态分配的数据、函数参数和返回值等。程序段主要是指程序本身和共享库等,也称为文本。

对于各个进程来说,用户数据显然都是惟一的,并且在进程运行时,用户数据的大小会随着进程的大小而发生变化,但程序段是静态的,对于运行该程序的各个进程来说都是完全相同的。

对于性能类问题,首先需要了解操作系统的资源开销情况,包括CPU、内存、I/O、网络等,如果存在单个资源开销过大,则可以结合具体的操作系统命令进行分析,如top、vmstat、iostat、netstat等。如果资源开销正常,则继续排查各类日志信息,包括操作系统日志、数据库集群日志等,查看日志中是否存在可疑点。如果在以上日志中没有发现任何异常,则需要进入数据库查看当前的等待事件和历史AWR信息。对于性能类问题,操作系统和数据库的基线对比尤为重要。

2.3.3 详解log file sync等待

数据库中的log file sync等待事件是指,当用户会话提交时,用户会话会通知LGWR(日志写)进程将redo缓存中的信息写入redo日志文件中,完成写操作后,LGWR进程再通知(post)用户会话写操作已经完成,用户会话接收到LGWR的通知后,提交操作才完成。因此,用户会话在没有收到LGWR的通知之前一直处于等待状态,具体的等待事件就是log file sync。根据实践经验,引起log file sync等待事件的原因有以下几种。

·事务过度提交,即应用程序过度提交或者回滚。

·存储I/O资源紧张,导致LGWR进程写速度缓慢。

·CPU资源紧张,LGWR进程无法获得相应的CPU时间片。

·RAC节点之间SCN同步。

·RAC节点之间CR(Consistent Read,读一致性)块传递。

·控制文件争用。

·提交方式。

不同的原因,其解决方法会有所不同,当多种原因混合在一起时,需要进行综合考虑。下面就来具体讲解上述原因所对应的解决方法。

1.事务过度提交

事务过度提交是引起log file sync等待事件的主要原因之一。前面提到过,在默认情况下,当事务提交时,LGWR进程会将事务相关的日志条目立即写至redo日志中,直到日志写成功之后才显示提交成功。因此事务提交越频繁,触发LGWR进程写操作就会越频繁,引起log file sync等待事件的可能性就越大。所以当因为事务过度提交而引起log file sync等待事件时,最好的解决方法是修改应用,将小事务变成大事务。可是在很多情况下,修改应用并不是一件简单的事情,需要应用厂商的配合。当应用厂商配合力度不足时,我们就需要在数据库端想办法了。幸运的是,从Oracle 10g开始,Oracle推出了新的数据库参数commit_write用于控制LGWR进程写日志操作,其默认值为空,即表示wait和immediate。也可以将其在线修改(即参数值修改后不需要重启数据库也能生效)为nowait和batch,表示事务提交时,LGWR进程并不会马上将事务相关条目写至日志文件中,而是以异步模式将相关条目批量(batch)写至日志文件中。但采用这种方法,在缓减了log file sync等待事件的同时,数据库异常宕机后可能会造成数据丢失的问题,所以需要特别注意。

当然,使用临时表或NOLOGGING选项,可以尽可能少地产生redo日志,这也是解决log file sync等待事件的方法之一。

图2-28所示的是AWR报告中的Key Instance Activity Stats信息,从中我们可以看到数据库的提交次数和redo产生量,可以根据系统本身的负载进行评估。截图中每秒的提交次数为66.15次,redo的产生速率大约为1MB/s,相对于正常时间段,这里的提交次数非常大,频繁提交在一定程度上严重影响了log file sync等待事件。

图2-28 Key Instance Activity Stats信息

2.存储I/O资源紧张

LGWR进程写redo日志的特征是以串行小I/O的方式连续写入,存储的IOPS能力对其的影响最大。当存储I/O资源紧张时,LGWR进程写日志的速度就会受到明显影响,从而出现log file sync等待事件。那么,如何确定log file sync等待事件是不是因为存储I/O资源紧张而导致的呢,通常情况下,我们只要检查以下两个方面就可以确定了。

1)检查存储的I/O资源是否紧张,例如,可以在AIX系统中通过topas命令观察磁盘的繁忙程度,如图2-29所示。

图2-29 AIX系统TOP监控磁盘信息

2)检查系统中log file parallel write等待事件和log file sync等待事件的时间差,如果两者的时间接近,则说明存储I/O资源紧张是引起log file sync等待事件的主要原因。log file parallel write等待事件和log file sync等待事件的关系如图2-30所示。

图2-30 提交流程图

我们可以通过V$EVENT_HISTOGRAM视图观察log file parallel write等待事件消耗时间的分布情况,命令如下所示:


SQL> select event, wait_time_milli,wait_count
2 from v$event_histogram
3 where event = 'log file parallel write';
EVENT                   WAIT_TIME_MILLI  WAIT_COUNT
----------------------- ---------------  ----------
log file parallel write     1                 22677
log file parallel write     2                   424
log file parallel write     4                   141
log file parallel write     8                   340
log file parallel write     16                 1401
log file parallel write     32                  812
log file parallel write     64                  391
log file parallel write     128                  21
log file parallel write     256                   6

如果log file sync等待事件是因为存储I/O资源紧张而引起的,那么我们可以采取如下措施。

·如果有空闲的物理磁盘,且这些物理磁盘的I/O性能能够满足系统要求,就可以将log file在线迁移至空闲物理盘中。如果空间允许,则还可以考虑将数据库的UNDO表空间在线迁移至其他盘,从而释放I/O压力。

·如果在线日志设置了多组成员,那么为了减少LGWR写日志操作,可以考虑删除其他成员,只保留一组。

3.RAC节点之间SCN同步

在RAC数据库中,为了达到一致性读的效果,需要将commit SCN同步/传播到所有节点上。SCN同步/传播的方法主要有两种:Lamport SCN和immediate commit propagation。其中,immediate commit propagation的方式也称为BOC(Broadcast On Commit)。

Oracle 10gR1及以下版本默认使用Lamport SCN方式,Lamport SCN方式是指一个节点上的commit SCN不会保证立刻同步/传播到所有节点,也就是说可能会延时同步/传播。对于一些实时性要求较高的RAC数据库来说,Lamport SCN方式是不可取的。如果希望commit SCN立刻同步/传播到所有节点,则需要手动修改参数MAX_COMMIT_PROPAGATION_DELAY=1。

从Oracle 10gR2开始,默认使用immediate commit propagation(BOC),即一个节点上的commit SCN会立刻同步/传播到所有节点(该方法受隐含参数_immediate_commit_propagation控制,默认为true)。

immediate commit propagation(BOC)的实现原理具体如下。

1)用户会话执行提交操作时,其将通知LGWR进程将redo缓存中的信息写入到redo日志文件中。

2)LGWR进程收到用户会话通知后,会将redo缓存中的信息写入redo日志文件中,同时LGWR进程将commit SCN同步/传播给远程的数据库实例的LMS(Lock Manager Server,锁管理服务器)进程。

3)远程数据库实例的LMS将commit SCN同步到本地SCN,然后通知提交实例的LMS进程,表示SCN同步已经完成。

4)当提交实例的LMS进程接收到所有远程数据库实例的LMS进程的通知后,提交实例的LMS进程再通知本地的LGWR进程所有节点SCN同步已经完成。

5)LGWR进程在完成了I/O操作和LMS进程通知后,LGWR进程将通知用户会话提交成功。用户会话在没有收到LGWR进程通知之前,一直处于log file sync等待的状态。

RAC节点之间SCN传递的指标可以在AWR报告中进行观察,如图2-31所示。

节点间的SCN同步较为频繁,并且故障点的log file sync等待大量存在于SCN上:P2即为SCN值(如图2-32所示)。

如果log file sync等待事件是由于RAC节点之间的SCN同步引起的,那么我们可以采取如下措施。

1)检查LMS进程的数量是否足够。

2)检查系统CPU的资源是否足够。

3)检查RAC节点之间的私有通信是否正常。

4)将隐含参数_immediate_commit_propagation设置为false,禁用immediate commit propagation特性。

图2-31 Global Messaging Statistics信息

图2-32 故障点等待事件信息

4.RAC节点之间CR块传递

Oracle为了保证实例恢复(Instance Recovery)机制,要求每一个当前块(current block)在本地节点实例(local instance)被修改后(modify/update),必须将该当前块相关的redo日志写入logfile后(也就是说要求LGWR进程必须在完成写入后才能返回),才能由LMS进程传输给其他节点使用,如图2-33所示。

某客户数据库出现log file sync等待事件,正是由于上述这种机制引起的。AWR报告如图2-34所示。

图2-33 当前块传递示意图

图2-34 AWR报告信息

如果log file sync等待事件是由于RAC节点之间的CR块传递引起的,那么我们可以采取如下措施。

1)修改应用,尽量避免跨节点获取数据。

2)将隐含参数_cr_server_log_flush的值修改为fasle(默认为true),关闭CR节点传输特性。

5.控制文件争用

LGWR进程在写日志的同时还会在控制文件中记录写进度。当因为控制文件争用而导致enq: CF-contention等待事件时,前台进程有可能会出现log file sync等待事件。图2-35所示的是AWR报告的部分数据截图。

图2-35 AWR中等待事件信息

LGWR进程在写日志的过程中需要更新控制文件。当RMAN操作比较频繁时(如利用RMAN批量删除归档),服务器进程也会更新控制文件,而多个会话同时更新控制文件时,可能会引起enq:CF-contention等待事件。当LGWR进程无法获得CF锁时,可能就会导致log file sync等待事件。这个案例再次表明了Oracle是一台巨大的同步机器,看起来似乎毫无关联的事物,往往存在着相互因果的关系。

6.提交方式

在Oracle 11.2.0.3版本以前,LGWR进程采用的是post/wait方式,当用户会话发起提交时,会通知LGWR进程将redo缓存中的信息写入redo日志文件中,当LGWR进程完成写操作之后,会立即通知用户会话写操作已经完成,用户会话在接收到LGWR的通知后,提交操作才全部完成。

从Oracle 11.2.0.3版本之后,LGWR进程引入了polling方式,当用户会话发起提交后进入睡眠(sleep)状态,LGWR进程将redo缓存中的信息写入到redo日志文件中,但LGWR进程并不会通知用户会话写操作已经完成,而是需要用户会话睡眠超时(user session sleep timeout)后通过轮询的方式查看写入是否已经完成。轮询机制下,用户会话变被动为主动,LGWR进程也会从通知中解放出来,释放大量CPU资源,但这也会导致用户会话长时间处于log file sync等待中。

Oracle会在这两种方式之间自动切换,这个特性称为“自适应日志同步机制”。切换历史也会记录到LGWR的trace(跟踪)文件中,内容输出如下:


Switch to polling:
*** 2012-10-02 08:15:47.049
kcrfw_update_adaptive_sync_mode: post->poll long#=316 sync#=1719 sync=247657
poll=12382 rw=6191 rw+=13890 ack=0 min_sleep=10023
*** 2012-10-02 08:15:47.050
Log file sync switching to polling
Current scheduling delay is 234 usec
Switch to post/wait:
***2012-10-02 08:16:23.325
kcrfw_update_adaptive_sync_mode: poll->post current_sched_delay=0
switch_sched_delay=234 current_sync_count_delta=2275
switch_sync_count_delta=1719
*** 2012-10-02 08:16:23.325
Log file sync switching to post/wait
Current approximate redo synch write rate is 758 per sec

同时,切换历史还会记录到v$sysstat视图中,代码如下:


SQL> select name,value from v$sysstat where name in 
('redo synch poll writes','redo synch polls');
NAME                                  VALUE
---------------------------------- --------
redo synch poll writes                    0
redo synch polls                          0

AWR报告中也有记录,如图2-36所示。

图2-36 AWR中切换信息记录截图

但这两种方式在切换的时候需要耗费大量系统性能,导致性能抖动,尤其是在繁忙的时候还会导致数据库的性能下降。

建议将_use_adaptive_log_file_sync参数设置为False(在线设置),关闭“自适应日志同步机制”,让LGWR进程使用post/wait模式,命令如下:


SQL> ALTER SYSTEM SET "_use_adaptive_log_file_sync"= 
    <FALSE/TRUE>  scope=<both/spfile/memory>;

2.3.4 10053跟踪诊断

当一个SQL出现性能问题时,可以使用SQL_TRACE或10046事件来跟踪SQL,通过生成的跟踪信息来了解SQL的执行过程。当我们查看一条SQL的执行计划时,只能看到CBO(Cost-Based Optimization,基于成本的优化)最终显示的执行计划结果,却并不知道CBO是根据什么来做的。如果遇到了执行计划异常,则可以借助Oracle 10053事件进行跟踪。10053事件是Oracle提供的用于跟踪SQL语句成本计算的内部事件,它能记载CBO模式下,Oracle优化器是如何计算SQL成本,并生成相应的执行计划的。

10053只对CBO有效,而且如果一个SQL语句已经解析过,就不会产生新的跟踪信息。

1)通过session级别跟踪,方法如下:


SQL> ALTER SESSION SET EVENTS='10053 trace name context forever, level 1';

或:


SQL> ALTER SESSION SET EVENTS='10053 trace name context forever, level 2';

执行相关SQL语句:


SQL> explain plan for select count(*) from obj$;
SQL> ALTER SESSION SET EVENTS '10053 trace name context off';

2)对特定session启用跟踪,方法如下。通过调用DBMS_SYSTEM.SET_EV包实现:


PROCEDURE SET_EV
Argument Name      Type              In/Out Default?
 ----------------- ----------------- ------ --------
 SI                BINARY_INTEGER    IN
 SE                BINARY_INTEGER    IN
 EV                BINARY_INTEGER    IN
 LE                BINARY_INTEGER    IN
 NM                VARCHAR2          IN

查询v$session视图,获取进程信息:


SQL> select sid,serial#,username from v$session where username is not null;
SID    SERIAL# USERNAME
-----  ------  ------------------------------
125    25      SYS

执行跟踪,命令如下:


SQL> exec dbms_system.SET_EV(125,25,10053,1,'');

结束跟踪,命令如下:


SQL> exec dbms_system.SET_EV(125,25,10053,0,'');

查询系统对应的会话跟踪文件,命令如下:


SQL> select value from v$diag_info where name = 'Default Trace File';

某客户核心系统新增了一条UPDATE SQL语句,该SQL语句执行异常缓慢(超过几个小时),最终失败回滚。该SQL语句相对比较简单,具体文本如图2-37所示。

图2-37 异常SQL语句

经过开发人员确认,该SQL语句在测试库(Linux+Oracle 12.2.0.1单机环境)中执行只需要几秒即可(数据量相差不大)完成,其中bs_loan_card_addition、bs_loan_card、bs_loan_contract_addition三张表的数据量都在200万行左右。

图2-38所示的是生产环境中该SQL的执行计划。

图2-38 生产环境下的执行计划

图2-39所示的是测试环境中该SQL的执行计划。

我们首先怀疑因为统计信息不准确,而导致CBO在访问BS_LOAN_CARD表的时候选择错误,本应该选择BS_LOAN_CARD_I3索引(因为"CUSTOMER_NO"='1000193229'的选择性很好,而这也是开发设计该索引的原因),但结果却选择了BS_LOAN_CARD_I0索引(对应的字段是BS_LOAN_CARD.LOAN_CARD_NO),而过滤条件中根本没有这个列,其只是作为关联条件与bs_loan_card_addition表进行连接。

图2-39 测试环境下的执行计划

因此,我们首先检查统计信息,意外地发现BS_LOAN_CARD.LOAN_CARD_NO列上居然存在一个HYBIRD类型的直方图,理论上来说,该值的唯一性是非常好的,不应该收集直方图。因此直接删除了该列上的直方图,再次检查发现执行计划仍未改变。

然后,我们尝试使用10053对该SQL执行计划的产生过程进行跟踪,发现生产环境下10053的跟踪结果如图2-40所示,测试环境下10053的跟踪结果如图2-41所示。

图2-40 生产环境下10053的跟踪结果

图2-41 测试环境下10053的跟踪结果

而且,SQL的执行计划信息如图2-42所示。

图2-42 SQL执行计划信息

这个执行计划简单理解就是,首先对BS_LOAN_CARD_ADDITION进行全表扫描,然后在所得的结果集里,将每一行的LOAN_CARD_NO列信息与BS_LOAN_CARD进行匹配,这就是第6步里面出现了一个"B"."LOAN_CARD_NO"=:B1原因,而这就是Oracle改写后的结果。因为其选择对BS_LOAN_CARD_ADDITION进行全表扫描,所以不可避免地就导致了效率的降低。而且,其后的rows估算为2444KB,这个大小是贴合实际的,所以之前即使删除了直方图也不会有结果。而测试上的改写结果明显与这个不一样,排除统计信息的影响,最大的可能就是CBO内部的算法选择存在问题,再结合那个可疑的“CBQT bypassed for query block UPD$1 (#0): Disabled by parameter.”提示信息,我们怀疑优化器参数在两个环境中存在区别。

于是,我们对比了生产和测试的跟踪文件中的优化器参数,如图2-43所示。

图2-43 生产环境中优化器的参数信息

然后,在测试环境中按以上参数进行同样的设置(会话级别),再次测试时我们会发现执行也变慢了,且执行计划与生产一致,继续缩小范围,最终定位到了_optimizer_squ_bottomup参数,如图2-44所示。

图2-44 测试环境设置参数后的执行计划

根据资料可以得知,CBQT(Cost-Based Query Transformation,基于代价的查询转换,也即CBO的SQL改写功能)会受到以下两个参数的影响。

·_optimizer_cost_based_transformation:设为默认值linear,其包含如下值:“exhaustive”“iterative”“linear”“on”“off”。

本例中该参数就是默认值,该参数可用于控制是否允许CBO改写。

·_optimizer_squ_bottomup:参数值为true(默认值),而其在生产环境中恰好相反为false,所以生产的跟踪文件中会有“Disabled by parameter”的信息。

查找资料“_optimizer_squ_bottomup enables unnesting of subquery in a bottom-up manner”,该参数默认为true,即开启子查询自底向上的展开功能(也就是类似于unnest hint的功能),unnest也称为子查询展开。

在MOS上搜索该参数可以发现很多相关Bug,如图2-45所示。

图2-45 “_optimizer_squ_bottomup”参数相关文档

本次故障的直接原因是在生产上修改了部分优化器相关的参数,该参数导致了CBO的部分优化功能无法实施,进而选择了并不算最优解的执行计划。而鉴于该参数是从一上线就已经设置好了的,因此为了避免因修改该参数而导致已有的SQL执行计划发生紊乱,最保险的方案是针对该SQL执行计划单独调整参数,即通过如图2-46所示的hint来实现。

图2-46 优化后的SQL语句