老熊的三分地-Oracle、UNIX、数据恢复

为11gR2 Grid Infrastructure增加新的public网络

老熊 — Wed, 25 Apr 2012 00:27:58 +0800

在某些环境下，运行11.2版本的RAC数据库的服务器上，连接了多个public网络，那么就会有如下的需求：

给其他的，或者说是新的public网络增加新的VIP地址。
在新的public网络上增加SCAN VIP.
在新的VIP地址上配置监听
在新的SCAN VIP地址上配置监听

实际上从11.2版本开始，grid infrastructure（以下可能会简写为GI）就是一个完整的clusterware，不仅仅是用于数据库，也可以用作应用软件的高可用性。上述的4个需求中，第1个是毫无疑问需要的；第2个需求对运行在grid infrastructure上的应用是必要的；第3个需求在运行在grid infrastructure上的数据库来说是必要的；第4个需求，是针对数据库的，这个需求有点难度，因为在一套grid infrastructure中只能允许有一个SCAN LISTENER的存在，由于可以不通过SCAN IP而是直接通过VIP地址连接数据库，所以这个新的SCAN监听可以不需要，但是为了完整，我们可以用变通的方法来实现。

下面我们用一个实例来演示如何实现上述的所有需求。

先简单介绍一下用于演示的环境：11.2.0.1 grid infrastructure for linux 32bit，共2个节点，节点名是xty3和xty4，没有使用DNS（实际上在有DNS的环境下，也不太可能会有第2个public network），所以下面的演示是以没有DNS来配置的。Grid Infrastructure用的是oracle用户安装的（实际生产建议用单独的grid用户），而RDBMS软件也是用oracle安装的。目前的private network是192.168.153.0，对应的网卡设备名是en1，public network是192.168.0.0，对应的网卡设备名是en0，打算新增加的public network是192.168.76.0，对应的网卡设备名是en2。

先看看/etc/hosts文件的内容：

127.0.0.1    localhost.localdomain localhost
::1             localhost6.localdomain6 localhost6
192.168.0.134   xty3
192.168.0.144   xty4
192.168.153.134 xty3-priv
192.168.153.144 xty4-priv
192.168.0.135   xty3-vip
192.168.0.145   xty4-vip
192.168.0.155   xty-cluster-svip1

第1步，配置好新的public network的IP地址和网络路由。注意新的public network IP地址配好后，注意配置好网络路由。

第2步，在所有的节点上编辑/etc/hosts文件，增加如下内容：

192.168.76.134   xty3-pub2
192.168.76.144   xty4-pub2
192.168.76.135   xty3-vip2
192.168.76.145   xty4-vip2
192.168.76.155   xty-cluster-svip2

192.168.76.134和192.168.76.144是两个节点上新的public network的public ip，192.168.76.135和192.168.76.145是相对应的VIP地址，而192.168.76.155则是准备要在新的public network上增加的SCAN IP。而xty-cluster-svip2则是新增的SCAN名字。

第3步，增加新的public network上的vip地址，这一步比较简单，用root用户执行下面的命令:

srvctl add vip -n xty3 -k 2 -A xty3-vip2/255.255.255.0/eth2
srvctl add vip -n xty4 -k 2 -A xty4-vip2/255.255.255.0/eth2

在上述命令中，-n参数后面跟的是节点名(hostname)； -k后面的参数表示第几个网络，这里是2，表示第2个public network。-A后面就是VIP地址的属性了，格式为”VIP地址名/子网/网卡设备名”。

然后用crsctl来检查，vip资源已经存在：

[root@xty3 ~]# crsctl stat res -t | egrep "vip|network"
ora.net1.network
ora.net2.network
ora.scan1.vip
ora.xty3-vip2.vip
ora.xty3.vip
ora.xty4-vip2.vip
ora.xty4.vip

[root@xty3 ~]# srvctl config vip -n xty3
VIP exists.:xty3
VIP exists.: /xty3-vip2/192.168.76.135/255.255.255.0/eth2
VIP exists.:xty3
VIP exists.: /xty3-vip/192.168.0.135/255.255.255.0/eth0

[root@xty3 ~]# srvctl config vip -n xty4
VIP exists.:xty4
VIP exists.: /xty4-vip2/192.168.76.145/255.255.255.0/eth2
VIP exists.:xty4
VIP exists.: /xty4-vip/192.168.0.145/255.255.255.0/eth0

ora.net2.network，ora.xty3-vip2.vip,ora.xty4-vip2.vip都是新增的资源。然后使用下面的命令启动新增的VIP：

[root@xty3 ~]# srvctl start vip -i xty3-vip2
[root@xty3 ~]# srvctl start vip -i xty4-vip2

使用ifconfig 命令也可以确认IP地址已经附加到了新增的public network上，即en2上。所以在这里，新增public network上的VIP配置成功。

第4步，我们来实现第3个需求，也就是在VIP地址上增加监听，这个步骤也很简单，用GI的用户(这个环境是oracle)执行下面的命令：

[oracle@xty3 root]$ srvctl add listener -l LISTENER_N2 -s -p 1521 -k 2
[oracle@xty3 root]$ srvctl config listener  -a
Name: LISTENER
Network: 1, Owner: oracle
Home: 
  /oracle/app/grid on node(s) xty4,xty3
End points: TCP:1521
Name: LISTENER_N2
Network: 2, Owner: oracle
Home: 
  /oracle/app/grid on node(s) xty4,xty3
End points: TCP:1521

启动并检查新增加的监听：

[oracle@xty3 root]$ srvctl start listener -l LISTENER_N2
[oracle@xty3 root]$ lsnrctl status listener_n2

LSNRCTL for Linux: Version 11.2.0.1.0 - Production on 24-APR-2012 21:07:44

Copyright (c) 1991, 2009, Oracle.  All rights reserved.

Connecting to (DESCRIPTION=(ADDRESS=(PROTOCOL=IPC)(KEY=LISTENER_N2)))
STATUS of the LISTENER
------------------------
Alias                     LISTENER_N2
Version                   TNSLSNR for Linux: Version 11.2.0.1.0 - Production
Start Date                24-APR-2012 21:04:14
Uptime                    0 days 0 hr. 3 min. 30 sec
Trace Level               off
Security                  ON: Local OS Authentication
SNMP                      OFF
Listener Parameter File   /oracle/app/grid/network/admin/listener.ora
Listener Log File         /oracle/app/grid/log/diag/tnslsnr/xty3/listener_n2/alert/log.xml
Listening Endpoints Summary...
  (DESCRIPTION=(ADDRESS=(PROTOCOL=ipc)(KEY=LISTENER_N2)))
  (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=192.168.76.135)(PORT=1521)))
The listener supports no services
The command completed successfully

可以看到，监听LISTENER_N2增加成功。增加监听也可以使用netca图形界面操作，但还是命令行操作快捷。不过从上面的输出可以看到，新的public network上的监听并没有监听到相对应的public固定IP。实际上他们监听hostname对应的IP地址。这是由BUG 8678541引起，在11.2.0.2及以上版本中已经修复。

第5步，我们来实现第2个需求，也就是增加SCAN IP，实际上在GI中，只能有一个SCAN，所以新增加的“SCAN IP”，实际上应称为“Application IP”，用两种方法，先介绍简单的，用root命令执行：

[root@xty3 ~]# appvipcfg create -network=2 -ip=192.168.76.155 -vipname=xty-cluster-svip2 -user=root
Production Copyright 2007, 2008, Oracle.All rights reserved
2012-04-24 21:29:23: Skipping type creation
2012-04-24 21:29:23: Create the Resource
2012-04-24 21:29:23: Executing cmd: /oracle/app/grid/bin/crsctl add resource xty-cluster-svip2 -type app.appvip.type -attr USR_ORA_VIP=192.168.76.155,START_DEPENDENCIES=hard(ora.net2.network) pullup(ora.net2.network),STOP_DEPENDENCIES=hard(ora.net2.network),ACL='owner:root:rwx,pgrp:root:r-x,other::r--,user:root:r-x'

然后查看并启动资源：

[root@xty3 ~]# crsctl stat res -t | grep svip2
xty-cluster-svip2
[root@xty3 ~]# crsctl start resource xty-cluster-svip2
CRS-2672: Attempting to start 'xty-cluster-svip2' on 'xty3'
CRS-2676: Start of 'xty-cluster-svip2' on 'xty3' succeeded

使用ifconfig命令可以确认IP地址已经加到新的public network上了，由于这个是类似”SCAN IP“的地址，只能在一个节点上起。我们可以用下面的命令来调整这个IP到另一个节点上：

[root@xty3 ~]# crsctl relocate resource xty-cluster-svip2
CRS-2673: Attempting to stop 'xty-cluster-svip2' on 'xty3'
CRS-2677: Stop of 'xty-cluster-svip2' on 'xty3' succeeded
CRS-2672: Attempting to start 'xty-cluster-svip2' on 'xty4'
CRS-2676: Start of 'xty-cluster-svip2' on 'xty4' succeeded
[root@xty3 ~]# crsctl stat res xty-cluster-svip2 -p | grep -i type
TYPE=app.appvip.type
[root@xty3 ~]# crsctl stat type app.appvip.type
TYPE_NAME=app.appvip.type
BASE_TYPE=cluster_resource

这个实现”SCAN IP“功能的application ip，不属于VIP，也不属于SCAN，因此这个资源是srvctl不能管理的。

下面介绍用第2种方法来实现新的public network上的”SCAN IP”。
把上面建好的资源xty-cluster-svip2停掉并删除：

[root@xty3 ~]# crsctl stop res xty-cluster-svip2
CRS-2673: Attempting to stop 'xty-cluster-svip2' on 'xty4'
CRS-2677: Stop of 'xty-cluster-svip2' on 'xty4' succeeded
[root@xty3 ~]# crsctl delete res xty-cluster-svip2

然后执行下面的命令生成现有的SCAN IP的属性：

[root@xty3 ~]# crsctl stat res ora.scan1.vip -p > /tmp/1.txt

接着手工修改一下/tmp/1.txt文件，下面列出修改的部分：

NAME=ora.n2_scan1.vip
SCAN_NAME=xty-cluster-svip2
DESCRIPTION=Oracle SCAN VIP resource on network2
SCAN_NAME=xty-cluster-svip2
START_DEPENDENCIES=hard(ora.net2.network) dispersion:active(type:ora.scan_vip.type) pullup(ora.net2.network)
STOP_DEPENDENCIES=hard(ora.net2.network)
USR_ORA_VIP=192.168.76.155

然后配置SCAN并启动:

[root@xty3 ~]# crsctl add resource ora.n2_scan1.vip -type ora.scan_vip.type -file /tmp/1.txt
[root@xty3 ~]# srvctl config scan
SCAN name: xty-cluster-svip2, Network: 2/192.168.76.0/255.255.255.0/eth2
SCAN VIP name: n2_scan1, IP: /xty-cluster-svip2/192.168.76.155
SCAN VIP name: scan1, IP: /xty-cluster-svip1/192.168.0.155
[root@xty3 ~]# crsctl start resource ora.n2_scan1.vip
CRS-2672: Attempting to start 'ora.n2_scan1.vip' on 'xty3'
CRS-2676: Start of 'ora.n2_scan1.vip' on 'xty3' succeeded

[root@xty3 ~]# crsctl relocate resource ora.n2_scan1.vip
CRS-2673: Attempting to stop 'ora.n2_scan1.vip' on 'xty3'
CRS-2677: Stop of 'ora.n2_scan1.vip' on 'xty3' succeeded
CRS-2672: Attempting to start 'ora.n2_scan1.vip' on 'xty4'
CRS-2676: Start of 'ora.n2_scan1.vip' on 'xty4' succeeded

注意第2种方法使用的SCAN VIP资源的名字跟第1种方法不一样，在实际使用中，可以根据需要选择即可。不过注意在第2种方法中不要用ora.scan1_n2.vip这样的名字，否则srvctl查看这个资源时会出错。
看上去srvctl显示的结果有点异常，只有一个SCAN Name，是新加的那个。不过至少可以用srvctl看到了，并且这也是可以理解的，因为目前就只能支持一个SCAN Name，在本文仅处于研究的目的，所以这种方法不建议使用于生产，建议使用上面的第1种方法。

到目前为止，新的public network上的SCAN已经增加成功。

第6步，在新配的SCAN VIP上配置一个SCAN LISTENER。注意不能使用srvctl add listener命令来配置，因为这种方式实际上是在所有的节点上都加了可同时启动的监听，需要增加的是scan listener。不过srvctl add scan_listener是不会成功的，因为它会检测到在1521端口上已经有了SCAN Listener，即使是在高版本的GI中，这个命令增加了-k 参数指定network，也是会报错的。因此只能使用类似上面第2种增加SCAN VIP的方法来增加新的SCAN Listener，不过这次需要用GI的安装用户（此环境是oracle用户）来执行操作：

[oracle@xty3 root]$ crsctl stat res  ora.LISTENER_SCAN1.lsnr -p > /tmp/2.txt

修改/tmp/2.txt文件，修改的行如下：

NAME=ora.LISTENER_N2_SCAN1.lsnr
DESCRIPTION=Oracle SCAN listener resource on network 2
START_DEPENDENCIES=hard(ora.n2_scan1.vip) dispersion:active(type:ora.scan_listener.type) pullup(ora.n2_scan1.vip)
STOP_DEPENDENCIES=hard(intermediate:ora.n2_scan1.vip)

然后配置SCAN Listener并启动：

[oracle@xty3 root]$ crsctl add resource ora.listener_n2_scan1.lsnr -type ora.scan_listener.type -file /tmp/2.txt
[oracle@xty3 root]$ srvctl config scan_listener
SCAN Listener LISTENER_N2_SCAN1 exists. Port: TCP:1521
SCAN Listener LISTENER_SCAN1 exists. Port: TCP:1521

[oracle@xty3 root]$ crsctl start resource ora.LISTENER_N2_SCAN1.lsnr
CRS-2672: Attempting to start 'ora.LISTENER_N2_SCAN1.lsnr' on 'xty4'
CRS-2676: Start of 'ora.LISTENER_N2_SCAN1.lsnr' on 'xty4' succeeded

可以看到新增的SCAN Listener成功在节点xty4上启动，当然在之前的操作步骤中，新的SCAN VIP即N2_SCAN2是启动到了xty4上，所以这个监听也会在xty4上。

我们把新的SCAN VIP调整到节点xty3上：

[root@xty3 ~]# crsctl relocate resource ora.n2_scan1.vip -f
CRS-2673: Attempting to stop 'ora.LISTENER_N2_SCAN1.lsnr' on 'xty4'
CRS-2677: Stop of 'ora.LISTENER_N2_SCAN1.lsnr' on 'xty4' succeeded
CRS-2673: Attempting to stop 'ora.n2_scan1.vip' on 'xty4'
CRS-2677: Stop of 'ora.n2_scan1.vip' on 'xty4' succeeded
CRS-2672: Attempting to start 'ora.n2_scan1.vip' on 'xty3'
CRS-2676: Start of 'ora.n2_scan1.vip' on 'xty3' succeeded
CRS-2672: Attempting to start 'ora.LISTENER_N2_SCAN1.lsnr' on 'xty3'
CRS-2676: Start of 'ora.LISTENER_N2_SCAN1.lsnr' on 'xty3' succeeded
[root@xty3 ~]# su oracle
[oracle@xty3 root]$ lsnrctl status LISTENER_N2_SCAN1

LSNRCTL for Linux: Version 11.2.0.1.0 - Production on 24-APR-2012 23:29:49

Copyright (c) 1991, 2009, Oracle.  All rights reserved.

Connecting to (DESCRIPTION=(ADDRESS=(PROTOCOL=IPC)(KEY=LISTENER_N2_SCAN1)))
STATUS of the LISTENER
------------------------
Alias                     LISTENER_N2_SCAN1
Version                   TNSLSNR for Linux: Version 11.2.0.1.0 - Production
Start Date                24-APR-2012 23:29:32
Uptime                    0 days 0 hr. 0 min. 17 sec
Trace Level               off
Security                  ON: Local OS Authentication
SNMP                      OFF
Listener Parameter File   /oracle/app/grid/network/admin/listener.ora
Listener Log File         /oracle/app/grid/log/diag/tnslsnr/xty3/listener_n2_scan1/alert/log.xml
Listening Endpoints Summary...
  (DESCRIPTION=(ADDRESS=(PROTOCOL=ipc)(KEY=LISTENER_N2_SCAN1)))
  (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=192.168.76.155)(PORT=1521)))
The listener supports no services
The command completed successfully

至此所有的操作已经完成。然后重启一下所有节点的crs，验证一下重启后是否正常。在关闭第1个节点的crs之后，第2个节点上顺利接管了所有的VIP地址，并且所有的SCAN Listener也运行到了节点2上。然后重启两个节点的crs后，一切看起来比较正常。唯一的不足是由于BUG 8678541引起的问题，使新的public network的VIP地址上的监听，监听到了错误的IP地址上。

以上的操作全部是针对Grid Infrastructure，不过在数据库上，还需要调整参数LISTENER_NETWORKS，而不能使用local_listener和remote_listener参数。这个参数的设置，举例如下：

alter system set LISTENER_NETWORKS='((NAME=network1)(LOCAL_LISTENER=192.168.0.135:1521)(REMOTE_LISTENER=xty-cluster-svip1:1521))','((NAME=network2)(LOCAL_LISTENER=192.168.76.135:1521)(REMOTE_LISTENER=xty-cluster-svip2:1521))' sid='inst1';

alter system set LISTENER_NETWORKS='((NAME=network1)(LOCAL_LISTENER=192.168.0.145:1521)(REMOTE_LISTENER=xty-cluster-svip1:1521))','((NAME=network2)(LOCAL_LISTENER=192.168.76.145:1521)(REMOTE_LISTENER=xty-cluster-svip2:1521))' sid='inst2';

实际上Grid Infrastructure已经是一个完整的clusterware，完全可以通过自定义的脚本来增加自己想要的资源，以实现高可用性。
本文参考了来自于MOS的文档《How to Configure A Second Listener on a Separate Network in 11.2 Grid Infrastructure [ID 1063571.1]》

--The End

防火墙、DCD与TCP Keep alive

老熊 — Tue, 17 Jan 2012 00:21:08 +0800

在以前我写的一篇文章《Oracle与防火墙》中提到，网络防火墙会切断长时间空闲的TCP连接，这个空闲时间具体多长可以在防火墙内部进行设置。防火墙切断连接之后，会有下面的可能：

切断连接之前，连接对应的Oracle会话正在执行一个耗时特别长的SQL，比如存储过程而在此过程中没有任何数据输出到客户端，这样当SQL执行完成之后，向客户端返回结果时，如果TCP连接已经被防火墙中断，这时候显然会出现错误，连接中断，那么会话也就会中断。但是客户端还不知道，会一直处于等待服务器返回结果的状态。
切断连接之前，Oracle会话一直处于空闲状态，在防火墙中断之后，客户端向Oracle服务器提交SQL时，由于TCP连接已经中断，这时客户端侦测到连接中断，那么客户端就会报ORA-3113/ORA-3114这类错误，然后会话中断。但是在Oracle服务器端，会话一直在处于等待客户端消息的状态。
当然，如果服务器和客户端都一直闲着，没有任何消息往来，那么客户端和客户端的会话就一直存在，直到客户端发送消息即提交SQL到Oracle服务器。

从上面的前面2种情况来看，防火墙切断数据库TCP连接，引起的后果就会有：

客户端报ORA-3113/3114错误，对这于长连接的后台应用不是个好事，特别是对那种C/C++开发的后台应用没有重连机制，就会出现问题或者程序退出。如果应用在一个较长的时间内没有任何活动，而这个时间超过了防火墙的设置，那应用的连接被中断。
对于有连接池或重连机制的应用，如果连接池过大，导致空闲连接过多，或者是防火墙的连接断开时间过短同时应用太闲，那么连接频繁地被中断，而在数据库服务器端，则连接越来越多，即会话数越来越多，甚至最终超过了数据为最大连接数。
其他一些影响，比如你在跑一个脚本而长时间没有输出，结果防火墙切断了连接，你之前的工作就白做，当然这些影响范围都较小。

那么如何防止出现以上的问题？对于没有重连机制的长连接应用，临时的解决办法是调大防火墙的连接切断时长；或者应用端在闲时定期执行一条类似于select 1 from dual这样的SQL；或者在Oracle服务端开启DCD功能，而DCD（死连接检测，即Dead Connection Detection)的时间长度短于防火墙的连接切断时长；或者使用操作系统的tcp keep-alive功能。对于有重连机制或有连接池的应用，为了避免数据库端连接数满，可以使用DCD或tcp keep-alive功能，如果DCD或TCP keep-alive的时间短于防火墙连接切断时长，那么连接将不会中断，因为防火墙视连接为活动状态（不过按MOS文档的说法，DCD的包有可能被防火墙忽略，即用DCD使连接保持活动状态可能没有作用）。而如果DCD或TCP keep-alive的时间长于防火墙连接切断时长，那么连接被中断的会话和进程将得到清理。

这里简单介绍一下TCP keep-alive，顾名思议，就是让TCP连接保持存活状态，这是由TCP协议层实现的功能，也是在TCP连接空闲时间超过设置的时间，就会发送探测包，因此，这个功能跟Oracle的DCD是极为类似的，所不同的是，这是由协议层实现的功能，是不能通过trace应用进程来跟踪包的发送。

理论是完美的，而现实差距越很远。

下面是一个有关的案例。一套运行在AIX 5.3上的RAC数据库，数据库版本为10.2.0.4，这套数据库在sqlnet.ora文件中有设置sqlnet.expire_time=5，后果却是，数据库的连接数过几天就要满一次，防火墙设置的时间是8小时，也就是说只会切断空闲时间超过8小时的连接，这个时间已经足够长，晚上系统太闲，总会有部分连接空闲时间过长，但是由于设置了DCD，连接应该不会被防火墙切断，而即使防火墙切断了连接，那么在DCD的作用下，数据库服务器端的会话和进程也应该被清理才是，即使DCD不起作用，那TCP keep-alive也应该起作用才是，那为什么会话和进程数越来越多，甚至达到了最大进程数或会话数呢？

检查应用服务器(weblogic）的连接池，并核对应用服务器到数据库的TCP连接，发现连接池监控中的连接数量并不多，而对比应用服务器上看到的到数据库数据库的TCP连接数量和数据库数据器上看到的应用服务器建立过来的TCP连接数量，二者之间差距非常大，前者远远小于后者，就是说，大量的连接已经被切断，应用服务器的连接已经退出，但是数据库端的连接还没有释放。从weblogic的日志来看，经常出现类似于连接失效并建立新的数据库连接这样的信息。

DCD为什么没有起作用，是不是DCD的BUG？DCD的确是有很多BUG，但是完全不工作的BUG应该是很少的。将sqlnet.expire_time设为1，5以及其他值，都不起作用，甚至重启过主机都没有起作用（当然并不是专门为了DCD而重启主机）。

使用truss命令来跟踪Oracle进程：


SQL> host
$ truss -p 828090
kread(0, 0x0000000000000000, 0) (sleeping...)
...很长时间没有任何反应...
^CPstatus: process is not stopped
$
$ exit

SQL> oradebug setospid 828090
Oracle pid: 247, Unix process pid: 828090, image: oracle@db2
SQL> oradebug short_stack
ksdxfstk+002c<-ksdxcb+04e4<-sspuser+0074<-000044C0<-nttrd+0120<-nsprecv+07a0<-nsrdr+0114<-nsdo+1710<-nsbrecv+0040<-nioqrc+04a8<-opikndf2+0688<-opitsk+08a8<-opiino+0990<-opiodr+0ae0<-opidrv+0484<-sou2o+0090<-opimai_real+01bc<-main+0098<-__start+0098
SQL>  oradebug short_stack
ksdxfstk+002c<-ksdxcb+04e4<-sspuser+0074<-000044C0<-nttrd+0120<-nsprecv+07a0<-nsrdr+0114<-nsdo+1710<-nsbrecv+0040<-nioqrc+04a8<-opikndf2+0688<-opitsk+08a8<-opiino+0990<-opiodr+0ae0<-opidrv+0484<-sou2o+0090<-opimai_real+01bc<-main+0098<-__start+0098

没有看到DCD起任何作用的迹象，使用truss跟踪其他多个空闲Oracle也是如此。

那么TCP keep-alive呢，怎么样来判断有没有起作用？在AIX上其答案是使用kdb（这个需要root用户权限）。

在笔记本电脑上使用sqlplus连接到数据库，在数据库主机上使用netstat -Aan | grep 1521 | grep “你的IP地址”，以获得sqlplus连接的TCP连接信息，显示的第1列是一串16数据，然后使用kdb：

#kdb
The specified kernel file is a 64-bit kernel
Preserving 1418178 bytes of symbol table
First symbol __mulh
           START              END <name >
0000000000001000 0000000003E5C050 start+000FD8
F00000002FF47600 F00000002FFDC940 __ublock+000000
000000002FF22FF4 000000002FF22FF8 environ+000000
000000002FF22FF8 000000002FF22FFC errno+000000
F100070F00000000 F100070F10000000 pvproc+000000
F100070F10000000 F100070F18000000 pvthread+000000
PFT:
PVT:
id....................0002
raddr.....0000000002000000 eaddr.....F200800090000000
size..............00080000 align.............00001000
valid..1 ros....0 fixlmb.1 seg....0 wimg...2
Command enhancement entry point is called.

 Welcome to VXDRV subcommands
Command enhancement entry for vxodmdb called.called.

 Welcome to vxdrv subcommands
(0)> sockinfo f100060009b04398 tcpcb | egrep "KEEP|opts"
    t_timer....... 00000000 (TCPT_KEEP)
    timewait.prv@0000000000000000  inp_v6opts  @0000000000000000
    opts........ 0004 (REUSEADDR)

可以看到，这个TCP连接没有KEEPALIVE选项（属性），keep-alive对应的timer(TCPT_KEEP)数值为0，表示没有设置timer时间。
会不会是DCD功能屏蔽了TCP keep-alive？
将sqlnet.ora中expire_time设置去掉，然后重复上述步骤，这次有了变化:

#kdb
The specified kernel file is a 64-bit kernel
Preserving 1418178 bytes of symbol table
First symbol __mulh
           START              END <name >
0000000000001000 0000000003E5C050 start+000FD8
F00000002FF47600 F00000002FFDC940 __ublock+000000
000000002FF22FF4 000000002FF22FF8 environ+000000
000000002FF22FF8 000000002FF22FFC errno+000000
F100070F00000000 F100070F10000000 pvproc+000000
F100070F10000000 F100070F18000000 pvthread+000000
PFT:
PVT:
id....................0002
raddr.....0000000002000000 eaddr.....F200800090000000
size..............00080000 align.............00001000
valid..1 ros....0 fixlmb.1 seg....0 wimg...2
Command enhancement entry point is called.

 Welcome to VXDRV subcommands
Command enhancement entry for vxodmdb called.called.

 Welcome to vxdrv subcommands
(0)> sockinfo f100060009c1b398 tcpcb | egrep "KEEP|opts"
    t_timer....... 00000464 (TCPT_KEEP)
    timewait.prv@0000000000000000  inp_v6opts  @0000000000000000
    opts........ 000C (REUSEADDR|KEEPALIVE)

可以看到，这个TCP连接已经有了KEEPALIVE选项(属性），同时keep-alive timer为16进制数464，即十进制1124，表示还有562秒（timer这里的时间以半秒为单位）就会发送keep-alive探测包。

反复通过加上DCD设置和去掉DCD设置进行测试，发现只要一加上DCD功能，那么Oracle进程就不会为TCP连接设置keep-alive选项（属性），反之则会设置keep-alive。从这里很明显地看出来，DCD功能开启后，不但没有起作用，还关闭了TCP keep-alive功能。

对于这套系统，最后去掉了DCD设置，并将所有的空闲连接清理掉，经过多天的观察，系统的连接数一直保持稳定，与应用服务器的实际连接数保持一致。

那是不是启用了DCD之后，TCP keep-alive就会被关闭，这里不能贸然下定论，不同的版本、不同的平台或许有差异，至少我一个同事在Linux上测试时，tcp keep-alive是共存的。

在诊断处理这个案例的过程之中，不得不提到另外一点，写在此处，与大家分享。在诊断问题的初期阶段，询问系统维护人员（通常连应用和数据库一起维护），应用服务器和数据库之间是否有防火墙，如果有，是怎么样设置的TCP连接断开时间。而维护人员最开始的回答是没有防火墙。从表面上看，也应该是没有防火墙。数据库服务器其中一个IP地址是192.168.8.42，而两台应用服务器服务器的IP地址是192.168.8.201和192.168.8.202，咋一看是在同一网段，中间应该不会有防火墙。然而仔细检查相关数据：

$ifconfig -a
....省略部分输出....
en4: flags=5e080867,c0<up ,BROADCAST,DEBUG,NOTRAILERS,RUNNING,SIMPLEX,MULTICAST,GROUPRT,64BIT,CHECKSUM_OFFLOAD(ACTIVE),PSEG,LARGESEND,CHAIN>
        inet 192.168.8.42 netmask 0xffffff80 broadcast 192.168.8.127
        inet 192.168.8.43 netmask 0xffffff80 broadcast 192.168.8.127
         tcp_sendspace 131072 tcp_recvspace 65536 rfc1323 0

可以看到，实际上数据库跟应用服务器是在不同的子网之中。这里子网掩码为0xffffff80，也就是我们通常写的子网掩码255.255.255.128，这样0-127为一个子网，128-255为一个子网（当然子网的第1个和最后一个地址都是不能使用的）。那么最后一个数字为201和202的两个IP地址显然就在第2个子网中，子网之间仍然需要有路由功能的网络设备，那么在之间有防火墙也是有可能的。用上面的方法去检查应用服务器的网络配置，发现其被划在了更小的子网之中。系统维护人员最终确认应用服务器和数据库之间的确是有防火墙存在。因此我们可以总结出两点：1，全面的知识对诊断数据库问题很有帮助。2，如果经过详尽分析问题发现与别人说的不一致，需要坚持，并需要为自己的坚持寻找更多的数据来证实。

--The End--

Oracle 10g CRS安装问题解决一例

老熊 — Fri, 23 Dec 2011 01:59:45 +0800

如同我在《我们应该怎样安装Oracle数据库？》这一篇文章提及，只要安装Oracle软件的时候严格按文档操作，通常不会遇到太大的问题。但是，现实环境总是那么复杂，在一些新的软件组合或者是新的版本上进行安装，容易遇到一些比较复杂的或者说是解决起来不是那么容易的问题。本文将要描述的就是在这样一个环境下的安装：HP-UX 11.31 IA64、Symantec SFRAC、Oracle 10g RAC。当安装CRS运行root.sh时，一直挂起，也就是说，root.sh一直过不去。下面列出这个问题的解决过程，供朋友们参考。

先来看看运行root.sh得到输出：

cwxndb01:[/oracle/app/oracle/product/crs]#./root.sh
WARNING: directory '/oracle/app/oracle/product' is not owned by root
WARNING: directory '/oracle/app/oracle' is not owned by root
WARNING: directory '/oracle/app' is not owned by root
WARNING: directory '/oracle' is not owned by root
Checking to see if Oracle CRS stack is already configured
Checking to see if any 9i GSD is up

Setting the permissions on OCR backup directory
Setting up NS directories
Oracle Cluster Registry configuration upgraded successfully
WARNING: directory '/oracle/app/oracle/product' is not owned by root
WARNING: directory '/oracle/app/oracle' is not owned by root
WARNING: directory '/oracle/app' is not owned by root
WARNING: directory '/oracle' is not owned by root
Successfully accumulated necessary OCR keys.
Using ports: CSS=49895 CRS=49896 EVMC=49898 and EVMR=49897.
node <nodenumber>: <nodename> <private interconnect name> <hostname>
node 0: cwxndb01 cwxndb01-priv cwxndb01
Creating OCR keys for user 'root', privgrp 'sys'..
Operation successful.
Now formatting voting device: /dev/vx/rdsk/vgdata01/lv_vote_128m_01
Now formatting voting device: /dev/vx/rdsk/vgdata02/lv_vote_128m_02
Now formatting voting device: /dev/vx/rdsk/vgdata03/lv_vote_128m_03
Format of 3 voting devices complete.
Startup will be queued to init within 30 seconds.

然后就在显示完”Startup will be queued to init within 30 seconds”之后就一直挂起。在安装CRS运行root.sh时，一般失败的情形是报错然后退出，很少有一直挂起的。

为了解决一个未知的问题，我们通常分为3步，了解当前正在做什么，当前所做的为什么会引起问题，解决问题。那么现在，我们需要知道的是root.sh这个脚本正在做什么，执行到了哪里。

使用”ps -ef | grep root.sh”命令，找到root.sh的pid，然后再寻找这个pid的子进程，一直定位到最末端，发现当前正在运行的命令是”sleep 60″，而”sleep 60″的上级命令是”init.cssd startcheck CSS”。
root.sh的核心其实在于$ORA_CRS_HOME/install/rootconfig这个脚本，在这个文件中，我们根据上述线索，找到下面的代码：
```
# Prepare to start the daemons.
$ID/init.crs start

# Check to see if they are going to start.
$ID/init.cssd startcheck CSS
if [ "$?" != "0" ]; then
  $ECHO CRS daemons not set to start. See $MSGFILE for details.
  exit 1
fi
```
实际上运行root.sh的输出中的”Startup will be queued to init within 30 seconds.”，正是init.crs start的显示。从root.sh当前运行的子进程来看，目前正在运行”$ID/init.cssd startcheck CSS”这一命令。所以接下来我们需要知道在这一个命令里面会一直挂起。

在HP-UX操作系统中，init.cssd在/sbin/init.d目录下，我们可以发现init.cssd也是一个比较复杂的脚本。为了搞清楚一个shell脚本执行到了哪里出了问题，我们可以使用sh -x以调试方式运行shell脚本。(实际上在分析root.sh当前正在进行的操作时，我们同样可以用sh -x ./root.sh这样的命令来运行。）

我们手工执行如下的命令：

   cd /sbin/init.d
   sh -x init.cssd startcheck CSS

然后发现在下面的代码中32-37行代码处挂起：


# check on vendor clusterware and filesystem dependencies.
# Startcheck is supposed to block for a long time waiting on dependencies.
'startcheck') # Returns 0 if we should start
              # Returns 1 on a non-cluster boot
              # Returns 2 if disabled by admin
              # Returns 3 on error

    # Check our startup run status, initialized by the automatic startup
    # or manual startup routes.
    $ID/init.cssd runcheck
    STATUS=$?
    if [ "$STATUS" != "0" ]; then
      exit $STATUS;
    fi

    # If we have vendor clusterware, and CLINFO indicates a non-clustered boot
    # then prevent CRS startup.
    if [ $USING_VC -eq 1 ]
    then
      # Run CLINFO to get cluster status. It returns 0 if the machine is
      # booting in clustered mode.
      $EVAL $CLINFO
      if [ "$?" != "0" ]; then
        $LOGMSG "Oracle Cluster Ready Services disabled by non-clustered boot."
        $ID/init.cssd norun
        exit 1;
      fi

      # Wait for the Vendor Clusterware to start
      $EVAL $VC_UP
      RC=$?
      while [ $RC -ne 0 ]; do
        $LOGMSG "Oracle Cluster Ready Services waiting for $VC_NAME to start."
        $SLEEP $DEP_CHECK_WAIT
        $EVAL $VC_UP
        RC=$?
      done
    fi

32-37行代码是一个循环，从代码注释上看，是在等待Vendor Clusterware启动。如果一直没有启动，就一直循环，也就是一直挂起。代码”$EVAL $VC_UP“用于判断Vendon Clusterware是否已启动。这里$VC_UP是什么值呢，在文件中搜索代码，可以找到如下的代码：

HP-UX) MACH_HARDWARE=`/bin/uname -m`
       CLUSTERDIR=/opt/nmapi/nmapi2
       if [ "$MACH_HARDWARE" = "ia64" ]; then
          SO_EXT=so
          NMAPIDIR_64=$CLUSTERDIR/lib/hpux64
       else
          SO_EXT=sl
          NMAPIDIR_64=$CLUSTERDIR/lib/pa20_64
       fi
       LD_LIBRARY_PATH=$ORA_CRS_HOME/lib:$NMAPIDIR_64:/usr/lib:$LD_LIBRARY_PATH
       export LD_LIBRARY_PATH
       # Presence of this file indicates that vendor clusterware is installed
       SKGXNLIB=${NMAPIDIR_64}/libnmapi2.${SO_EXT}
       if [ -f $SKGXNLIB ]; then
         USING_VC=1
       fi

       VC_UP="$PSEF | $GREP '/usr/lbin/cm[g]msd' 1>$NULL 2>$NULL"
       # NOTE: Not supporting Hardware partitioning machines.
       REBOOT_TOC="/var/opt/oracle/bin/reboot_toc"
       if [ -x $REBOOT_TOC ]; then
       FAST_REBOOT="$REBOOT_TOC || /usr/sbin/reboot -r -n -q"
       SLOW_REBOOT="/bin/kill -HUP `$CAT /var/run/syslog.pid` ; /bin/sync & $SLEEP 2 ; $REBOOT_TOC || /usr/sbin/reboot -r -n -q"
       else
         FAST_REBOOT="/usr/sbin/reboot -r -n -q"
         SLOW_REBOOT="/bin/kill -HUP `$CAT /var/run/syslog.pid` ; /bin/sync & $SLEEP 2 ; /usr/sbin/reboot -r -n -q"
       fi
       DFL_CLSINFO=$CLUSTERDIR/bin/clsinfo
       if [ $USING_VC -eq 0 ]; then
          # We are not using vendor clusterware.
          VC_NAME=""
          VC_UP=/bin/true
          CLINFO=/bin/true
          # We do not have a slow reboot without vendor clusterware
          SLOW_REBOOT=$FAST_REBOOT
       elif [ -f $DFL_CLSINFO ]; then
          # We are using Generic HP Vendor Clusterware
          VC_NAME="Generic HP-UX Vendor Clusterware"
          VC_UP=/bin/true
          CLINFO=$DFL_CLSINFO
       else
          # We are using HPUX ServiceGuard Clusterware
          VC_NAME="HP-UX Service Guard"
          CLINFO=/bin/true
       fi

       ID=/sbin/init.d

以上一段代码的主要意思是：如果存在/opt/nmapi/nmapi2/libnmapi2.so文件，那么表示系统使用了Vendor Clusterware，也就是使用了第三方集群软件。如果存在/opt/nmapi/nmapi2/bin/clsinfo文件，则表示系统使用了其他的第三方集群软件，并且该文件可以执行用于判断是否已经启动Vendor Clusterware，即VC_UP=/opt/nmapi/nmapi2/bin/clsinfo。如果不存在该文件，表示系统使用的是HP ServiceGuard，那么VC_UP=”$PSEF | $GREP ‘/usr/lbin/cm[g]msd’ 1>$NULL 2>$NULL” ,即判断cm开头的一些进程是否在运行，用来判断Service Guard是否在运行。从sh -x执行结果来看，脚本认为系统用的是Service Guard，很显然，这个是错误的，一直在等待Service Guard启动，那这样很明显就会一直等待而挂起。

那么到目前为止，可以知道是由于错误地判断了Vendor Clusterware引起了问题，那么用于判断Vendor Clusterware的文件/opt/nmapi/nmapi2/bin/clsinfo应该不存在于系统中。/opt/nmapi/nmapi2/bin目录下的确没有clsinfo这个文件。而/opt/nmapi/nmapi2/lib目录下存在相应的库文件：

cwxndb01:[/opt/nmapi/nmapi2/lib/hpux64]#ll
total 0
lr-xr-xr-x   1 bin        bin             27 Jul 18 13:33 libnmapi2.so -> /usr/lib/hpux64/libvcsmm.so

可以看到库文件用的是symantec sfrac的库文件。
而bin目录下没有任意文件，看起来应该是symantec sfrac安装的BUG。

那怎么样来解决这个问题呢，知道了原因，解决就很简单了：

cwxndb01:[/opt/nmapi/nmapi2]#cd /opt/nmapi/nmapi2/bin
cwxndb01:[/opt/nmapi/nmapi2/bin]#ln -s /opt/VRTSvcs/ops/bin/clsinfo

只需要在这个目录下建一个链接即可。做完上述操作后，再清理掉环境，重新运行root.sh，一切顺利。

这个问题引起的根本原因，看起来是Symantec SFRAC安装的一个bug。不过总的来说，新版本的SFRAC环境下安装RAC数据库已经方便很多，跟普通方式安装CRS没有任何区别，而早期版本的SFRAC环境下安装RAC，需要使用SFRAC提供的专用界面进行安装。

--The End---

修改隐含参数_library_cache_advice解决性能问题一例

老熊 — Mon, 03 Oct 2011 01:10:26 +0800

客户的一套重要生产系统，出现了性能问题。这个问题涉及的信息如下：

数据库主机的CPU利用率长期在100%左右。
应用系统在晚上进行调整后，开始出现了问题。
数据库中出现大量的latch: shared pool、latch: library cache、cursor: pin S、latch: cache buffers chains和latch: cache buffers lru chain等各种等待。
由于系统较大，整个系统实际上被分成了2个部分，每个部分服务不同的用户。二者的应用基本相同，分别对应2套数据库，二者也同样在出问题之前进行了调整，而数据库的主机配置及参数也是相同的，同时均为10.2.0.5双节点RAC数据库。但是只有其中1套库有性能问题。
2套库的配置虽然没有差别，但是负载方式却有很大的区别，正常的那套库，2个节点的负载基本上是均衡的，而现在有性能问题的这套库，所有的负载基本上全部在第1个节点上（虽然已经多次要求开发商整改，不幸的是…这里不用说了）。

下面是AWR报告中的数据：

性能正常时间段的数据（采集时间2小时）：

              Snap Id      Snap Time      Sessions Curs/Sess
            --------- ------------------- -------- ---------
Begin Snap:      3408 19-Sep-11 09:00:21     4,690      39.5
  End Snap:      3412 19-Sep-11 11:00:07     4,950      38.7
   Elapsed:              119.76 (mins)
   DB Time:            2,900.95 (mins)

Cache Sizes
~~~~~~~~~~~                       Begin        End
                             ---------- ----------
               Buffer Cache:    35,840M    35,840M  Std Block Size:         8K
           Shared Pool Size:     6,144M     6,144M      Log Buffer:    30,632K

Load Profile
~~~~~~~~~~~~                            Per Second       Per Transaction
                                   ---------------       ---------------
                  Redo size:          1,968,314.84              6,360.04
              Logical reads:          1,038,182.89              3,354.59
              Block changes:            148,577.35                480.09
             Physical reads:              3,541.98                 11.44
            Physical writes:                546.31                  1.77
                 User calls:              7,811.87                 25.24
                     Parses:              3,187.30                 10.30
                Hard parses:                 10.07                  0.03
                      Sorts:              6,258.90                 20.22
                     Logons:                  9.65                  0.03
                   Executes:             24,100.52                 77.87
               Transactions:                309.48
Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
            Buffer Nowait %:  100.00       Redo NoWait %:  100.00
            Buffer  Hit   %:   99.69    In-memory Sort %:  100.00
            Library Hit   %:   99.36        Soft Parse %:   99.68
         Execute to Parse %:   86.77         Latch Hit %:   99.64
Parse CPU to Parse Elapsd %:   45.61     % Non-Parse CPU:   99.46

 Shared Pool Statistics        Begin    End
                              ------  ------
             Memory Usage %:   95.44   94.46
    % SQL with executions>1:   89.10   77.18
  % Memory for SQL w/exec>1:   87.82   76.62

Top 5 Timed Events                                         Avg %Total
~~~~~~~~~~~~~~~~~~                                        wait   Call
Event                                 Waits    Time (s)   (ms)   Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
CPU time                                        114,107          65.6
db file sequential read           8,232,067      40,956      5   23.5   User I/O
db file scattered read              929,509       2,392      3    1.4   User I/O
log file sync                     2,119,459       2,372      1    1.4     Commit
SQL*Net message from dblink       1,375,619       1,576      1    0.9    Network
          -------------------------------------------------------------
^LWait Events                         DB/Inst: CRM2DB/crm2db1  Snaps: 3408-3412
-> s  - second
-> cs - centisecond -     100th of a second
-> ms - millisecond -    1000th of a second
-> us - microsecond - 1000000th of a second
-> ordered by wait time desc, waits desc (idle events last)
-> %Timeouts: value of 0 indicates value was <  .5%.  Value of null is truly 0

                                                                  Avg
                                            %Time  Total Wait    wait     Waits
Event                                 Waits -outs    Time (s)    (ms)      /txn
---------------------------- -------------- ----- ----------- ------- ---------
db file sequential read           8,232,067   N/A      40,956       5       3.7
db file scattered read              929,509   N/A       2,392       3       0.4
log file sync                     2,119,459     0       2,372       1       1.0
SQL*Net message from dblink       1,375,619   N/A       1,576       1       0.6
SQL*Net more data from clien      1,871,442   N/A       1,428       1       0.8
control file sequential read      3,010,438   N/A       1,179       0       1.4
Backup: sbtbackup                        12   N/A       1,167   97243       0.0
gc cr grant 2-way                 3,688,572   N/A         993       0       1.7
log file parallel write           2,205,552   N/A         974       0       1.0
gc cr multi block request         2,378,748   N/A         721       0       1.1
gc current block 2-way            1,941,104   N/A         693       0       0.9
SQL*Net more data to client       5,142,664   N/A         498       0       2.3
gc buffer busy                      166,717     0         428       3       0.1
direct path read                    424,645   N/A         344       1       0.2
db file parallel read                61,816   N/A         298       5       0.0
enq: HW - contention                 17,487     0         216      12       0.0
db file parallel write              221,865   N/A         210       1       0.1
Backup: sbtwrite2                    36,271   N/A         145       4       0.0
gc current grant 2-way              445,456   N/A         115       0       0.2
enq: TM - contention                    255    74         102     400       0.0

在应用调整第2天上午的awr数据（采集时长1小时）：

Load Profile
~~~~~~~~~~~~                            Per Second       Per Transaction
                                   ---------------       ---------------
                  Redo size:          2,420,236.58              6,734.48
              Logical reads:          1,277,888.60              3,555.82
              Block changes:            164,638.57                458.12
             Physical reads:              1,208.59                  3.36
            Physical writes:                456.79                  1.27
                 User calls:              8,785.42                 24.45
                     Parses:              4,103.35                 11.42
                Hard parses:                 12.87                  0.04
                      Sorts:              8,052.30                 22.41
                     Logons:                  9.05                  0.03
                   Executes:             32,573.41                 90.64
               Transactions:                359.38

  % Blocks changed per Read:   12.88    Recursive Call %:    85.01
 Rollback per transaction %:    0.19       Rows per Sort:     8.74

Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
            Buffer Nowait %:   99.97       Redo NoWait %:  100.00
            Buffer  Hit   %:   99.92    In-memory Sort %:  100.00
            Library Hit   %:   99.92        Soft Parse %:   99.69
         Execute to Parse %:   87.40         Latch Hit %:   99.33
Parse CPU to Parse Elapsd %:   29.94     % Non-Parse CPU:   99.17

 Shared Pool Statistics        Begin    End
                              ------  ------
             Memory Usage %:   95.42   95.02
    % SQL with executions>1:   61.41   72.38
  % Memory for SQL w/exec>1:   60.04   73.07

Top 5 Timed Events                                         Avg %Total
~~~~~~~~~~~~~~~~~~                                        wait   Call
Event                                 Waits    Time (s)   (ms)   Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
CPU time                                         69,736          56.2
Backup: sbtwrite2                 2,319,231      22,510     10   18.1 Administra
db file sequential read           3,476,830      20,923      6   16.9   User I/O
latch: shared pool                  159,416       9,280     58    7.5 Concurrenc
Backup: sbtbackup                        28       2,746  98056    2.2 Administra
          -------------------------------------------------------------
^LWait Events                         DB/Inst: CRM2DB/crm2db1  Snaps: 3602-3604
-> s  - second
-> cs - centisecond -     100th of a second
-> ms - millisecond -    1000th of a second
-> us - microsecond - 1000000th of a second
-> ordered by wait time desc, waits desc (idle events last)
-> %Timeouts: value of 0 indicates value was <  .5%.  Value of null is truly 0

                                                                  Avg
                                            %Time  Total Wait    wait     Waits
Event                                 Waits -outs    Time (s)    (ms)      /txn
---------------------------- -------------- ----- ----------- ------- ---------
Backup: sbtwrite2                 2,319,231   N/A      22,510      10       1.8
db file sequential read           3,476,830   N/A      20,923       6       2.7
latch: shared pool                  159,416   N/A       9,280      58       0.1
Backup: sbtbackup                        28   N/A       2,746   98056       0.0
log file sync                     1,283,319     0       2,538       2       1.0
gc buffer busy                    1,088,432     0       2,324       2       0.8
latch: library cache                 31,278   N/A       1,328      42       0.0
control file sequential read      1,512,218   N/A       1,082       1       1.2
log file parallel write           1,157,491   N/A       1,045       1       0.9
SQL*Net message from dblink         952,956   N/A         987       1       0.7
SQL*Net more data from clien        962,454   N/A         837       1       0.7
kst: async disk IO                   17,574   N/A         483      27       0.0
gc cr grant 2-way                 1,539,289   N/A         439       0       1.2
gc current block 2-way              946,330   N/A         353       0       0.7
direct path read                    291,853   N/A         313       1       0.2
db file parallel write              261,735   N/A         298       1       0.2
read by other session                92,451     0         270       3       0.1
cursor: pin S                   304,676,088   N/A         233       0     235.1
db file scattered read               28,062   N/A         132       5       0.0
enq: TX - row lock contentio            466    52         123     263       0.0
direct path write                   227,989   N/A         113       0       0.2

从Load profile数据对比来看，应用调整后系统负载有一定的提高，同时每事务逻辑读也有一定的增加（不足10%）。这会是个问题吗？
从第2份数据来看，latch: shared pool 和 latch: library cache有明显的增加。

下面的是性能问题更加严重的时候的AWR数据（采集时长为2小时）：

              Snap Id      Snap Time      Sessions Curs/Sess
            --------- ------------------- -------- ---------
Begin Snap:      3744 26-Sep-11 09:00:01     4,504      38.2
  End Snap:      3748 26-Sep-11 11:00:26     4,916      52.7
   Elapsed:              120.41 (mins)
   DB Time:           21,868.27 (mins)

Cache Sizes
~~~~~~~~~~~                       Begin        End
                             ---------- ----------
               Buffer Cache:    35,840M    35,840M  Std Block Size:         8K
           Shared Pool Size:     6,144M     6,144M      Log Buffer:    30,632K

Load Profile
~~~~~~~~~~~~                            Per Second       Per Transaction
                                   ---------------       ---------------
                  Redo size:          1,790,430.57              5,945.33
              Logical reads:          1,162,875.15              3,861.46
              Block changes:            154,064.15                511.59
             Physical reads:              3,007.80                  9.99
            Physical writes:                337.21                  1.12
                 User calls:              8,227.28                 27.32
                     Parses:              3,603.24                 11.96
                Hard parses:                 11.25                  0.04
                      Sorts:              7,304.40                 24.26
                     Logons:                 11.27                  0.04
                   Executes:             25,994.53                 86.32
               Transactions:                301.15

  % Blocks changed per Read:   13.25    Recursive Call %:    82.87
 Rollback per transaction %:    0.21       Rows per Sort:     8.14

Instance Efficiency Percentages (Target 100%)
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
            Buffer Nowait %:   99.99       Redo NoWait %:  100.00
            Buffer  Hit   %:   99.75    In-memory Sort %:  100.00
            Library Hit   %:   99.94        Soft Parse %:   99.69
         Execute to Parse %:   86.14         Latch Hit %:   98.90
Parse CPU to Parse Elapsd %:   14.69     % Non-Parse CPU:   84.51

 Shared Pool Statistics        Begin    End
                              ------  ------
             Memory Usage %:   95.48   94.33
    % SQL with executions>1:   87.63   74.92
  % Memory for SQL w/exec>1:   86.52   74.66

Top 5 Timed Events                                         Avg %Total
~~~~~~~~~~~~~~~~~~                                        wait   Call
Event                                 Waits    Time (s)   (ms)   Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
latch: shared pool                  991,918     274,715    277   20.9 Concurrenc
latch: library cache                941,443     232,344    247   17.7 Concurrenc
CPU time                                        212,150          16.2
cursor: pin S                  ############     115,049      0    8.8      Other
latch: cache buffers lru chain    1,106,570      96,442     87    7.4      Other
          -------------------------------------------------------------
^LWait Events                         DB/Inst: CRM2DB/crm2db1  Snaps: 3744-3748
-> s  - second
-> cs - centisecond -     100th of a second
-> ms - millisecond -    1000th of a second
-> us - microsecond - 1000000th of a second
-> ordered by wait time desc, waits desc (idle events last)
-> %Timeouts: value of 0 indicates value was < .5%.  Value of null is truly 0

                                                                  Avg
                                            %Time  Total Wait    wait     Waits
Event                                 Waits -outs    Time (s)    (ms)      /txn
---------------------------- -------------- ----- ----------- ------- ---------
latch: shared pool                  991,918   N/A     274,715     277       0.5
latch: library cache                941,443   N/A     232,344     247       0.4
cursor: pin S                 9,095,470,035   N/A     115,049       0   4,180.5
latch: cache buffers lru cha      1,106,570   N/A      96,442      87       0.5
db file sequential read           7,819,285   N/A      49,564       6       3.6
latch: cache buffers chains         511,936   N/A      35,753      70       0.2
latch free                           95,257     0      14,609     153       0.0
latch: object queue header o        221,907   N/A      14,378      65       0.1
log file sync                     2,156,343     1      11,496       5       1.0
cursor: pin S wait on X             422,320   100       4,603      11       0.2
gc cr grant 2-way                 3,526,856     0       3,430       1       1.6
db file scattered read              624,480   N/A       3,083       5       0.3
enq: TX - row lock contentio          5,946    88       2,600     437       0.0
latch: row cache objects             16,983   N/A       2,281     134       0.0
SQL*Net message from dblink       1,284,487   N/A       2,179       2       0.6
gc buffer busy                      353,228     0       2,054       6       0.2
gc cr multi block request         2,499,709     0       1,974       1       1.1
gc current block 2-way            1,969,516     0       1,920       1       0.9
SQL*Net more data from clien      1,667,513   N/A       1,914       1       0.8
control file sequential read      2,974,349   N/A       1,735       1       1.4
db file parallel read               230,795   N/A       1,645       7       0.1
log file parallel write           1,581,432   N/A       1,303       1       0.7
Backup: sbtbackup                        14   N/A         730   52120       0.0
buffer busy waits                   143,869     0         488       3       0.1
latch: library cache lock             5,058   N/A         378      75       0.0
enq: HW - contention                 22,039     0         370      17       0.0
gc current grant 2-way              424,243   N/A         357       1       0.2
enq: SQ - contention                  5,010     1         354      71       0.0
read by other session                50,153     0         339       7       0.0
direct path read                    324,226   N/A         305       1       0.1
db file parallel write              207,793   N/A         274       1       0.1
row cache lock                      175,301     0         263       1       0.1

从第3份数据来看，性能更为恶化，情形更为复杂。

那么针对这个性能现象，可以提出如下的问题：

最直观的，最容易想到的就是，性能问题的出现是否与应用调整有关，如果是，为什么另一套库没有出现问题？会不会是另一套库的负载在2个节点都有相对均衡的负担，而出问题的库，负载全部集中在1个节点上引起？
客户是在应用调整几天后才报告性能问题，这个问题会不会是一个逐渐出现的问题？如果一开始就有严重的性能问题，那么应该会很快报告。不过中间跨了一个周末，所以对于”逐渐出现问题“的判断又加了一些难度。
这么多的性能问题相关的现象中，哪个更贴近问题的原因？实际上在主机的CPU长期保持在100%左右时，会放大平时的一些轻微的问题，或者引起另一些问题。从等待来看，latch: cache buffers chains和cursor: pin S都会引起CPU的急剧增加，而其他的latch竞争同样也会引起CPU的上升，虽然上升没有前者大。到底是SQL执行效率不高引起CPU急剧增加然后引起了shared pool latch等与解析相关的资源争用还是因为解析相关的问题导致CPU急剧增加引起了cache buffers chains等与SQL执行相关的latch争用？或者是2者的共同作用？

下面首先来分析，会不会是应用调整引起的问题，也就是说，是不是由SQL引起的问题。如果是SQL引起的问题，会有几种可能，1是部分频繁执行的SQL执行效率变差；2是增加了很多的硬解析；3是并发增加或者说是SQL的执行次数有上升。仔细检查对比现在和以前的AWR数据，可以排除第1和2这种可能。至于第3种，可能略有增加，但是不一定跟应用调整有关，毕竟正常情况下业务量的变化也是有可能的。所以应用调整引起问题的可能性较小。

会不会是因为负载过大引起的问题，这个很容易验证。取业务低谷期，比如下班时间的数据，进行分析可以发现，既然在CPU在稍低(75%以下）的时候，仍然有大量的library cache latch的争用。下面是取自周日19:00-20:00的AWR数据（注：本文涉及故障的分析时间是在星期一）：

Top 5 Timed Events                                         Avg %Total
~~~~~~~~~~~~~~~~~~                                        wait   Call
Event                                 Waits    Time (s)   (ms)   Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
CPU time                                         49,224          48.3
latch: shared pool                  185,951      41,178    221   40.4 Concurrenc
latch: library cache                 45,636       8,861    194    8.7 Concurrenc
db file sequential read             815,066       4,763      6    4.7   User I/O
cursor: pin S                  ############       1,732      0    1.7      Other
          -------------------------------------------------------------

                                                                  Avg
                                            %Time  Total Wait    wait     Waits
Event                                 Waits -outs    Time (s)    (ms)      /txn
---------------------------- -------------- ----- ----------- ------- ---------
latch: shared pool                  185,951   N/A      41,178     221       0.6
latch: library cache                 45,636   N/A       8,861     194       0.2
db file sequential read             815,066   N/A       4,763       6       2.8
cursor: pin S                 1,890,998,700   N/A       1,732       0   6,459.2
latch free                            8,549     0       1,278     150       0.0
control file sequential read      1,507,789   N/A         466       0       5.2
Backup: sbtbackup                         7   N/A         428   61096       0.0
log file sync                       285,442     0         309       1       1.0
SQL*Net more data from clien        145,137   N/A         221       2       0.5
db file scattered read               67,716   N/A         173       3       0.2
gc buffer busy                       56,842     0         135       2       0.2
gc cr grant 2-way                   359,146   N/A          99       0       1.2
SQL*Net message from dblink         123,206   N/A          98       1       0.4
log file parallel write             289,048   N/A          91       0       1.0
SQL*Net more data to client       1,242,471   N/A          79       0       4.2
gc current block 2-way              179,654   N/A          66       0       0.6
direct path read                     62,336   N/A          65       1       0.2
gc cr multi block request           228,693   N/A          52       0       0.8

至于性能问题是不是逐渐引起的，这个问题目前并不关键，暂时不考虑。只是做为后面分析问题的一个参考。

再看最后一个问题，这些性能现象中，哪一个更接近问题的原因？幸庆的是，从上面的业务低谷期数据可以看到，这个时候的等待主要是跟解析相关的等待，而其他的latch: cache buffers lru chain等与SQL执行期相关的等待已经不再明显。

所以到此阶段的结论是：性能并不是由于应用调整引起、与负载关系不是太大、主要是与shared pool latch等解析相关的争用有关。
进一步分析上面的数据，其实可以看到latch: shared pool的等待时间占主导地位，同时由于shared pool latch的争用也会一定程度上引起library cache latch的争用（请参考我的另一篇文章《shared pool latch和library cache latch》），所以我们这里主要考虑是什么引起了shared pool latch的争用。另外，cursor: pin S的等待是一个极少出现的等待，一般是由于bug或者高并发地执行同一条SQL引起。那么，cursor: pin S会跟shared pool latch的争用有所关联么？目前不得而知。或者这3者都是相关的？

基于上面的分析，下面重点来分析shared pool latch的争用。使用上面提及的业务低谷期的AWR数据，因为这个时候没有了其他的干扰，更容易分析：

^LLatch Miss Sources                  DB/Inst: CRM2DB/crm2db1  Snaps: 3716-3718
-> only latches with sleeps are shown
-> ordered by name, sleeps desc

                                                     NoWait              Waiter
Latch Name               Where                       Misses     Sleeps   Sleeps
------------------------ -------------------------- ------- ---------- --------
library cache            kglpndl: child: after proc       0     19,599       55
library cache            kglpndl: child: before pro       0     12,653    1,969
library cache            kglpnp: child                    0     10,188   34,808
library cache            kglLockCursor                    0        632    1,539
library cache            kglhdgn: child:                  0        487    3,729
library cache            kglobpn: child:                  0        408    2,077
library cache            kgldte: child 0                  0        381      747
library cache            kglukp: child                    0        184       66
library cache            kglati                           0         52        1
library cache            kqlmbpil: parent                 0         52        4
library cache            kglpin                           0         38        9
library cache            kgldti: 2child                   0         32        0
library cache            kglhdbrnl: child                 0         13       29
library cache            kglhdgc: child:                  0          9        0
library cache            kglobld                          0          4        0
library cache            kglic                            0          2        7
library cache            kglini: child                    0          1        0
shared pool              kghupr1                          0    168,465  148,602
shared pool              kghalo                           0      9,881   23,589
shared pool              kghfre                           0      7,136   13,425
shared pool              kghfrunp: clatch: nowait         0        470        0
shared pool              kghalp                           0        204       82
shared pool              kghfrunp: alloc: wait            0          9        0
shared pool              kghfrunp: clatch: wait           0          5       15
shared pool              kghasp                           0          4        0
shared pool              kghfrh                           0          3        0
shared pool simulator    kglsim_unpin_simhp               0        319       70
shared pool simulator    kglsim_scan_lru: scan            0          3      101
shared pool simulator    kglsim_upd_newhp                 0          3       89
shared pool simulator    kglsim_chg_simhp_free            0          1       25
slave class create       ksvcreate                        0          2        0

那么从Latch Miss Source的数据可以看到，对于shared pool latch，绝大部分的sleep发生在kghupr1这个函数这里。在oracle中kghupr1这个函数是干什么的呢，简单来说就是un-pin recreatable内存块，其主要目的是要将creatable的内存块链接到shared pool的LRU链表中，在这个过程中要持有shared pool latch。这里我们可以确认不是由于在shared pool中的内存分配引起了latch的争用，而是在sql的execute阶段完成后才应该发生的争用。

从上面的数据同样可以看到，library cache latch的争用主要发生在kglpndl (KGL PiN DeLete)。

再来考虑cursor: pin S等待，这个等待通常发生在2个时间点，第1个是在SQL软解析对cursor进行PIN时增加mutex的引用计数时发生；第2个是在cursor执行完un-PIN时，减少mutex的引用计数时发生。

实际上在SQL整个执行过程中，除了parse阶段，在execute完成后（注意，可能是在fetch完成之前）同样会有shared pool latch、shared pool latch的获取。因为执行后要执行很多的操作，比如将recreated chunk链接到LRU链表中，更新sql的统计信息，un-pin cursor以及引用的某些对象等待。

以上三者，将线索都指向了SQL语句execute完成之后的阶段，这里execute指的是SQL语句的open-parse-execute-fetch-close等诸多步骤中的一个，而不是我们通常所讲的”执行“。

从出现性能问题后的几个不同时间段的AWR报告中，从数据上看现象是一致的，上述结论是可以成立的。

如果是一个问题的事后分析，到现在这里，如果再继续深入就非常困难了。还好在分析问题时，问题依然存在。

通过对数据库的实时分析，可以发现以下几点：

latch: shared pool、latch: library cache、cursor: pin S这三种基本上都是同时出现，这也验证了前面的结论，这3者是相关的。
等待cursor: pin S的会话其当前的SQL通常为2条并发量很高的SQL，这几条SQL都是存储过程中的SQL，而执行存储过程并发量很高。latch: library cache等待的会话当前的SQL也类似此现象，当然这样的话library cache latch的争用就发生在极少数的child latch上。
等待latch: shared pool的会话其当前的SQL绝大部分为空，这似乎验证了之前提到的shared pool latch的争用发生在SQL执行完之后。同时shared pool latch争用全部发生在同一个child latch上，这个是极不寻常的。

然后使用来自Tanel Poder的脚本@latchprof进行更深入的分析：

SQL> @latchprofx sid,name,ksllwnam,ksllwlbl % library 10000
  SID NAME            KSLLWNAM                            KSLLWLBL  Held Gets  Held %     Held ms
----- --------------- ----------------------------------- -------- ----- ---- ------- -----------
 3146 library cache   kglpndl: child: after processing    latch     2442    4   24.42    4595.844
 3138 library cache   kglpndl: child: after processing    latch     2274    4   22.74    4279.668
  694 library cache   kglpndl: child: before processing   latch     1443    2   14.43    2715.726
 4198 library cache   kglpndl: child: after processing    latch     1214    2   12.14    2284.748
  611 library cache   kglpndl: child: after processing    latch     1157    2   11.57    2177.474
  638 library cache   kglpndl: child: before processing   latch     1123    2   11.23    2113.486
 5949 library cache   kglobpn: child:                     latch     1103   24   11.03    2075.846
 5949 library cache   kglukp: child                       child     1062    6   10.62    1998.684
  584 library cache   kglpndl: child: before processing   latch      974    3    9.74    1833.068
 5762 library cache   kglpndl: child: before processing   latch      960    2    9.60    1806.720
 5204 library cache   kgllkdl: child: no lock handle      latch      923    1    9.23    1737.086
 5949 library cache   kghfrunp: clatch: nowait                       888   17    8.88    1671.216
 2338 library cache   kglpndl: child: after processing    latch      823    2    8.23    1548.886
 6243 library cache   kglpndl: child: before processing   latch      822    2    8.22    1547.004
 6184 library cache   kglpndl: child: before processing   latch      790    2    7.90    1486.780
 4121 library cache   kglpndl: child: after processing    latch      684    2    6.84    1287.288
 5601 library cache   kglpndl: child: before processing   latch      675    1    6.75    1270.350
 3948 library cache   kglpndl: child: before processing   latch      657    1    6.57    1236.474
 3277 library cache   kglpndl: child: before processing   latch      652    1    6.52    1227.064

SQL> @latchprofx sid,name,ksllwnam,ksllwlbl % shared 10000
 SID NAME                   KSLLWNAM            KSLLWLBL      Held       Gets  Held %     Held ms
---- ---------------------- ------------------- ------------- ---- ---------- ------- -----------
2338 shared pool            kghupr1             Chunk Header  2173          5   21.73    4343.827
2338 shared pool simulator  kglsim_unpin_simhp                2172          4   21.72    4341.828
5710 shared pool            kghalo                            1107         15   11.07    2212.893
3423 shared pool simulator  kglsim_unpin_simhp                1075          2   10.75    2148.925
3423 shared pool            kghupr1             Chunk Header  1075          2   10.75    2148.925
5348 shared pool simulator  kglsim_unpin_simhp                1025          2   10.25    2048.975
5348 shared pool            kghupr1             Chunk Header  1025          2   10.25    2048.975
2895 shared pool            kghupr1             Chunk Header   767          2    7.67    1533.233
2895 shared pool simulator  kglsim_unpin_simhp                 767          2    7.67    1533.233
4779 shared pool            kghupr1             Chunk Header   609          1    6.09    1217.391
2602 shared pool            kghupr1             Chunk Header   551          2    5.51    1101.449
2602 shared pool simulator  kglsim_unpin_simhp                 550          1    5.50    1099.450
4591 shared pool            kghupr1             Chunk Header   523          1    5.23    1045.477
5164 shared pool simulator  kglsim_unpin_simhp                 518          1    5.18    1035.482
5164 shared pool            kghupr1             Chunk Header   518          1    5.18    1035.482
3677 shared pool            kghupr1             Chunk Header   493          1    4.93     985.507
3040 shared pool            kghalo                             329          1    3.29     657.671
2146 shared pool            kghupr1             Chunk Header   272          1    2.72     543.728
2146 shared pool simulator  kglsim_unpin_simhp                 272          1    2.72     543.728
5949 shared pool            kghalo                              63         63     .63     125.937
5949 shared pool simulator  kglsim_unpin_simhp                  28          3     .28      55.972
5949 shared pool            kghupr1             Chunk Header    28          3     .28      55.972
5949 shared pool simulator  kglsim_upd_newhp                     5          5     .05       9.995
   0 shared pool            kghalo                               5          5     .05       9.995
1558 shared pool            kghalo                               3          3     .03       5.997
 682 shared pool            kghalo                               2          2     .02       3.998

实际上在处理问题时，还查询了v$mutex_sleep的数据，不过在写这篇文章时，已经找不到了:)

当然latchprof这个脚本反复执行多次，以确认不会只是一个偶然的结果。从数据上来看，跟AWR的数据是相吻合的。然而，在shared pool latch请求的数据上有了新的发现，同一个会话，在kghupr1过程中请求和持有shared pool latch的时间，与kglsim_unpin_simhp过程中请求和持有shared pool simulator latch的时间几乎是一致的。这是一个很重要的发现!

查看shared pool simulator latch的level，发现其比shared pool latch的level高，这就是说，完全有可能shared pool latch的持有之后又去请求shared pool simulator latch，而由于shared pool simulator latch的竞争，而最终导致了shared pool latch的竞争。

shared pool simulator latch用于保护shared pool simulator相关的内存区域。那么shared pool simulator是干什么的呢？简单地说就是用于shared pool advisor。当library cache object被刷出shared pool时，将这个对象的关键信息比如hash value记录下来，当对象load时，会查找这个对象在之前是否存在过，以此来计算shared pool增加一定数量的内存时，会使Shared pool 增加多少命中率。可参考”KGL simulator, shared pool simulator and buffer cache simulator – what are these?“和http://stackoverflow.com/questions/183963/what-is-the-oracle-kgl-simulator。

而在MOS上，使用shared pool simulator为关键字搜索，可以找到一些BUG，比如”TST PERF _LIBRARY_CACHE_ADVICE CAUSES MORE SHARED POOL AND SIMULATOR LATCH GETS“，这个BUG虽然在10.2.0.5中已经修复，但其描述的现象至少证明了当shared pool simulator争用时，将导致shared pool latch的争用。

那么这个问题，到现在为止，大体上可以判断为shared pool simulator latch的争用引起了问题，接下来在业务不太繁忙时间将”_library_cache_advice”参数在线修改为FALSE，观察系统，发现系统有短暂的时间负载冲高，但是很快就恢复到以往的正常水平，长时间的观察发现性能问题已经解决。

虽然性能问题已经解决，但是留下来需要更深入的问题还有：

cursor: pin S这个等待，在shared pool simulator latch争用时，是如何产生的？
share pool simulator latch的争用是如何产生的，为什么之前没有，是什么引起的？是BUG吗？如果是BUG又是怎么触发的？实际上后面尝试将”_library_cache_advice”参数改回为TRUE，但是该性能问题并没有再次出现。

不幸的是，上述的问题都不容易回答。

写到这里，不得不写一点与trouble shooting方法相关的话题。对于一个问题，有的人喜欢找到问题的根源，然后去彻底解决它；有的人喜欢想办法先解决问题再说，至于找原因，事后再找。实际上我是介于二者之间。对于问题，首先尝试去分析产生的原因，即root cause，如果在某个时间点上，能够得到解决办法，或者寻找原因的时间过长，那么就会先偏向于解决问题。实际上针对这个案例，在问题解决之后其根源还没找到，但是如果只是一味去寻找原因，那毫无疑问，时间将会很长，即便是有原厂参与，这已经涉及到比较internal的东西。但是客户的系统能等那么久吗？显然不能。另外，对于一些解决方案，比如这个案例，修改隐含参数，因为没有找到根源，实际上当时并没有100%的把握，然而我是幸运的，因为客户信任我，才让实施这种不会100%能解决问题的方案。在不能100%保证能解决问题的情况下，可以做以下评估：就算不能解决问题，会不会有负面影响？针对这个案例来说，首先实施是在业务低谷期，负载不是最高的时候；其二，对于这个参数相对应的功能有相当的了解，比如shared pool advisor和db cache advisor我一直认为是比较鸡肋的功能，关闭之后对系统基本没什么影响。

解决问题，有时称之为排除问题，实际上就是排除一个个可能存在问题的点。而有时候的排除，需要一定的试验性质。有的客户总是希望什么问题只有在100%完全能够证明的情况下才允许对系统进行更改，不幸的是，很多复杂的问题，这样做几乎是不可能完成的任务。

同时，对于这个案例，如果仅从AWR很难发现这个问题，与shared pool simulator latch的争用有关，这个latch的等待时间与shared pool latch、library cache latch、cursor: pin S的等待相比，是如此的短。比如在分析问题的当天，性能问题最突出的2小时内，shared pool latch的等待时间为274,715秒，而shared pool simulator latch的等待时间只不过1555秒，甚至还不及row cache objects latch等待的2316秒。而shared pool simulator latch的miss percent也只不过0.1%，远远小于shared pool latch和library cache latch的miss percent。但是通过AWR分析给我们指明了方向，然后通过数据库的实时数据分析，最终找到了解决办法。

--后面有点乱，写好几个小时，思绪有点乱了….
--the end.

在存储过程中的clob数据类型

老熊 — Wed, 28 Sep 2011 23:24:51 +0800

客户新上线的一套重要生产系统，某个存储过程每小时调用约11万次，每次调用的逻辑读超过了10000，消耗的CPU占数据库CPU Time的25-30%。很显然，这样一个存储过程是值得优化的。

不幸的是，这个存储过程的业务逻辑很复杂，光是参数就有9个。而存储过程所在的包其代码超过了1万行。通过复查代码的方式，耗时耗力，还不一定能够找出问题。

诊断性能问题，首要的是了解这个存储过程所大概要完成的业务功能，然后通过trace或instrument收集足够详细的性能数据。从客户和开发商那里了解到，存在性能问题的存储过程，主要用于系统之间的数据查询接口，根据不同的参数输入查询不同的数据，那么，对于这种小数据量的存储过程，可以考虑使用10046事件来分析是哪些SQL产生了这么多的逻辑读。

但是通过10046事件，发现存储过程中实际执行的SQL并不多，同时并没有逻辑读高的SQL语句。也许问题并没有出现在SQL语句中，而是出现在存储过程中其他非SQL部分。虽然用10046没有找到SQL语句，但还是有重大发现，在过程执行时，大量的逻辑读来自于current方式的读，这显示不是通常的SELECT语句所产生的。接下来我们用dbms_profiler来分析存储过程：

select dbms_profiler.start_profiler from dual;
exec intf.CRM_SERVICE_INTF.QueryService(.....);
exec dbms_profiler.stop_profiler;

然后使用来自MOS文档“Implementing and Using the PL/SQL Profiler [ID 243755.1]”中的profiler.sql脚本，生成一个profiler的结果文件，格式为html。下面是部分的内容：

点击其显示的代码行(line)，跳转到相应的源代码，发现大量的字符串拼接代码，很明显是用于拼接成XML格式。这很容易理解，因为现在系统之间的文本数据交互，xml几乎成了标准。从上面的截图中也可以看到很多类型于xml:=xml || ‘xxxx’ 这样的代码。是这样的代码引起的问题吗？

检查代码发现，这里用于拼接字符串的变量xml，被定义为clob类型，这引起了我极大的关注。在oracle的标准数据类型中，lob类型由于其能够存储大数据的本质，导致其内部格式和操作是最复杂的。有理由怀疑是clob的大量拼接引起的问题。

在有怀疑对象后，我们可以构造下面的测试来进行验证：

首先创建下面3个不同的存储过程，但是实现的功能是一致的：

create or replace procedure p1 ( v_out out clob)
is
  v_lob clob;
begin
  v_lob:='';
  for rec in (select object_name from dba_objects where rownum< =1000) loop
      v_lob:=v_lob || rec.object_name;
  end loop;
  v_out:=v_lob;
end;
/

      
create or replace procedure p2 ( v_out out clob)
is
  v_lob varchar2(32767);
begin
  v_lob:='';
  for rec in (select object_name from dba_objects where rownum<=1000) loop
      v_lob:=v_lob || rec.object_name;
  end loop;
  v_out:=v_lob;
end;
/

create or replace procedure p3 ( v_out out clob)
is
  v_lob clob;
  v_str varchar2(32767);
  v_cnt number;
begin
  v_lob:='';
  v_cnt:=0;
  v_str:='';
  for rec in (select object_name from dba_objects where rownum<=1000) loop
        v_str:=v_str || rec.object_name;
        v_cnt:=v_cnt+1;
        if v_cnt = 50 then
           v_cnt:=0;
           v_lob:=v_lob || v_str;
           v_str:='';
        end if;   
  end loop;
  if v_cnt <>0 then
     v_lob:=v_lob || v_str;
  end if;   
  v_out:=v_lob;
end;
/

第1个存储过程，P1，完全使用clob类型来拼接字符串；第2个存储过程，P2，使用varchar2类型拼接字符串，只有在过程最后将varchar2转成clob；第3个存储过程，P3，先使用varchar2类型拼接成较长的字符串，然后再用较长的字符串用clob类型来拼接。

下面看看P1和P2的差距：


SQL> var v_lob1 clob;
SQL> var v_lob2 clob;
SQL> begin
  2    sys.runstats_pkg.rs_start;
  3    p1(:v_lob1);
  4    sys.runstats_pkg.rs_middle;
  5    p2(:v_lob2);
  6    sys.runstats_pkg.rs_stop;
  7  end;
  8  /
Run1 ran in 5 hsecs
Run2 ran in 0 hsecs
run 1 ran in 50000000% of the time

Name                                  Run1        Run2        Diff
STAT...lob reads                       999           0        -999
LATCH.cache buffers lru chain        1,000           0      -1,000
STAT...free buffer requested         1,012           9      -1,003
STAT...lob writes                    2,000           1      -1,999
STAT...lob writes unaligned          2,000           1      -1,999
LATCH.object queue header oper       2,024           9      -2,015
STAT...consistent gets               3,581         580      -3,001
STAT...consistent gets from ca       3,581         580      -3,001
STAT...consistent changes            5,051          42      -5,009
STAT...db block changes              5,061          52      -5,009
STAT...calls to get snapshot s       7,008          10      -6,998
STAT...db block gets from cach      14,075          57     -14,018
STAT...db block gets                14,075          57     -14,018
STAT...session logical reads        17,656         637     -17,019
LATCH.cache buffers chains          46,151       1,083     -45,068
STAT...session uga memory          138,608      15,072    -123,536
STAT...session uga memory max      315,052     131,024    -184,028
STAT...session pga memory max      393,216     131,072    -262,144
STAT...session pga memory          393,216      65,536    -327,680

Run1 latches total versus runs -- difference and pct
Run1        Run2        Diff       Pct
49,789       1,674     -48,115  2,974.25%

PL/SQL 过程已成功完成。

从上面的数据来看，差距是巨大的，执行P1时产生的一致性读(consistent gets)和当前模式读(db block gets)，都远远大于执行P2时产生的一致读和当前模式读。特别是大量的db block gets验证了之前使用10046事件跟踪存储过程执行得到的结果。上面的数据中，甚至是会话消耗的内存都有很明显的差异。同时，还有其他对性能显著影响的地方，cache buffers chains latch，cache buffers lru chain latch，object queue header operation latch，这3种latch的获取次数是相当多的，在大并发时无疑将引起争用。实际上，在客户的这套系统中，这3种latch的争用经常出现，只是目前还没形成特别严重的后果。

再看看P1和P3的差异：


SQL> var v_lob1 clob;
SQL> var v_lob2 clob;
SQL> begin
  2    sys.runstats_pkg.rs_start;
  3    p1(:v_lob1);
  4    sys.runstats_pkg.rs_middle;
  5    p3(:v_lob2);
  6    sys.runstats_pkg.rs_stop;
  7  end;
  8  /
Run1 ran in 7 hsecs
Run2 ran in 2 hsecs
run 1 ran in 350% of the time

Name                                                      Run1        Run2        Diff
STAT...lob reads                       999          19        -980
LATCH.cache buffers lru chain        1,002          20        -982
STAT...free buffer requested         1,012          29        -983
STAT...lob writes                    2,000          40      -1,960
STAT...lob writes unaligned          2,000          40      -1,960
LATCH.object queue header oper       2,016          49      -1,967
STAT...consistent gets from ca       3,579         639      -2,940
STAT...consistent gets               3,579         639      -2,940
STAT...consistent changes            5,051         143      -4,908
STAT...db block changes              5,061         153      -4,908
STAT...calls to get snapshot s       7,007         146      -6,861
STAT...db block gets                14,075         346     -13,729
STAT...db block gets from cach      14,075         346     -13,729
STAT...session logical reads        17,654         985     -16,669
LATCH.cache buffers chains          46,147       1,999     -44,148
STAT...session uga memory          189,012      65,464    -123,548
STAT...session pga memory          196,608      65,536    -131,072
STAT...session pga memory max      262,144      65,536    -196,608
STAT...session uga memory max      315,052      65,560    -249,492

Run1 latches total versus runs -- difference and pct
Run1        Run2        Diff       Pct
49,380       2,264     -47,116  2,181.10%

二者的差异同样很明显。

不仅如此，在存储过程中，执行P1过程之后，甚至在临时表空间中产生了临时段，而这个临时段是不会自动清除的，经测试，即使没有用于返回结果的clob参数，在过程内部生成的clob所占的临时段也不会自动清除，只有会话退出才会清除掉。如果更深入跟踪，也许可以发现大量的逻辑读来源于这个临时段。

SQL> select tablespace,contents,segtype,blocks from v$sort_usage;

TABLESPACE                      CONTENTS  SEGTYPE       BLOCKS
------------------------------- --------- --------- ----------
TEMP                            TEMPORARY LOB_DATA         128

通过验证，证明clob类型的数据的确是引起客户系统中存储过程大量逻辑读和Latch争用的原因，找到了这个原因，优化就相对简单了。

在PL/SQL存储过程中，clob是相当方便的一种数据类型，由于其能够存储超长字符数据的特性，使得在这种用于数据交换的存储过程中用得较多。然而，从上面的数据中，不难发现，如果大量使用clob运算，将普通的字符串拼接成clob，其CPU消耗、逻辑读、甚至是latch的获取都是非常高的，对性能影响非常大。实际上在10g中，存储过程中的varchar2类型，其长度最大可以达到32767，所以如果返回的结果确保不超过这个长度，完全可以使用varchar2类型，只是在返回时再转换为clob，正如上面的存储过程P2所做的那样。如果其长度超过了32767，也可以如存储过程P3一样，先将短小的字符串拼接成较大的字符串，然后将较大的字符串拼接到clob中。

Hint的常见错误使用方式

老熊 — Fri, 09 Sep 2011 00:14:01 +0800

提起Oracle数据库的Hint，几乎每一个DBA都知道这一强大工具。在Oracle中，Hint可以用来改变SQL的执行计划、固定SQL的执行计划。Oracle数据库内部的很多特性也依赖于Hint，比如Outline、Profile等。

但是在日常工作中，很多开发人员或DBA，对Hint的使用仍然存在一些错误的方式。下面将列举主要的2种。（本文不讨论Hint的滥用即过度使用问题）。

1. NOLOGGING的不正确使用。

很多人知道，在进行数据处理时，如果不产生日志或只产生少量的日志，将会有明显的、甚至是巨大的效率提升。下面有几条不同的SQL：

INSERT INTO T1 NOLOGGING;
INSERT INTO T1 SELECT * FROM T2 NOLOGGING;
INSERT /*+ NOLOGGING */ INTO T1 VALUES ('0');
INSERT /*+ NOLOGGING */ INTO T1 SELECT * FROM T2;
DELETE /*+ NOLOGGING */ FROM T1;
UPDATE /*+ NOLOGGING */ T1 SET A='1';

实际上，上述所有的SQL没有一个能够实现“不产生”日志的数据更改操作。第1-2条SQL语句虽然没有将NOLOGGING写为Hint的形式，但是也是很多人的错误写法，一并列在此处。事实上，NOLOGGING并不是Oracle的一个有效的Hint，而是一个SQL关键字，通常用于DDL语句中。这里NOLOGGING相当于给SELECT的表指定了一个别名为“NOLOGGING”。下面是NOLOGGING的一些正确用法：

CREATE TABLE T1 NOLOGGING AS SELECT * FROM T2;
CREATE INDEX T1_IDX ON T1(A) NOLOGGING;
ALTER INDEX T1_IDX REDUILD ONLINE NOLOGGING;
ALTER TABLE T1 NOLOGGING;

上述SQL中，最后一条SQL只是将表的LOGGING属性改为”NO”。而之前的几条SQL能够有效地减少DDL操作时减少的日志量。

在DML操作中，只有下面一种方式能够在大数据量时仍然只会产生极少量的日志：

INSERT /*+ APPEND */ INTO T1 SELECT * FROM T2;

也就是使用append hint。但是这个hint要达到目的，需要以下几个条件：

使用INSERT /*+ APPEND */ INTO .. SELECT .. FROM形式的INSERT SQL。
如果是在归档模式下，需要将表的LOGGING属性置为NO。
表空间或数据库的FORCE LOGGING属性为NO。注意在非归档模式下也是可以设置FORCE LOGGING的。

这里提到的insert语句中的append hint，对于索引，仍然会产生日志，也就是说append hint对索引是没有效果的。
另外，DDL中使用的nologging关键字和inset语句中使用的append hint，并不是说完全不产生日志，只是对表的数据块的数据部分的更改不会有日志产生，但是SQL执行过程中数据字典的更改、空间分配等递归SQL、段头和位图块的更改、将数据块标记为unrecoverable等仍然会产生少量日志。

2. Hint的不正确写法。

这是一个比较不容易发现的问题。下面几条SQL，哪一条SQL的append hint会生效：

1. INSERT /*+ append,parallel(t1) */ INTO T1 SELECT * FROM T2;
2. INSERT /*+ parallel(t1), append */ INTO T1 SELECT * FROM T2;
3. INSERT /*+ this is append */ INTO T1 SELECT * FROM T2;
4. INSERT /*+ this append */ INTO T1 SELECT * FROM T2;

要回答这个问题，请先看下面的测试（测试环境：10.2.0.1 for Windows）：

SQL> INSERT /*+ append,parallel(t1) */ INTO T1 SELECT * FROM T2;
已创建55640行。
统计信息
----------------------------------------------------------
      12304  redo size
SQL> COMMIT;

SQL> INSERT /*+ parallel(t1), append */ INTO T1 SELECT * FROM T2;
已创建55640行。
统计信息
----------------------------------------------------------
    5739584  redo size
SQL> COMMIT;

SQL> INSERT /*+ this is append */ INTO T1 SELECT * FROM T2;
已创建55640行。
统计信息
----------------------------------------------------------
    5746604  redo size
SQL> COMMIT;

SQL> INSERT /*+ this append */ INTO T1 SELECT * FROM T2;
已创建55640行。
统计信息
----------------------------------------------------------
      12052  redo size
SQL> COMMIT;

从上面的输出可以看到，通过insert语句执行产生的redo size判断，4条SQL语句中，1和4这2条SQL中的append hint起了作用，而2和3这2条SQL中的append hint没有起作用。我们看看第1和第2条SQL，只不过是parallel和append换了个位置，结果就截然不同；而第3和第4条SQL，只是一个多了”is”这个词，另一个没有，其结果也完全不同。这里有什么玄机吗？

这里就需要了解Oracle在解析SQL时，是怎样解析hint的。
Oracle在解析hint，从左到右进行，如果遇到一个词是oracle关键字或者说是保留字，将忽略这个词以及之后的所有词。如果遇到的一个词即不是关键字也不是hint，就忽略该词。如果遇到的一个词是有效的hint，那么就会保留该hint。

Oracle的保留字或者说是关键词（虽然二者在意义不一样，但这里不将其区分），可以通过视图v$reserved_words来查询。”is”正是一个关键词，甚至连”,”（逗号）也是一个关键词。这样，上面的第2和第3条SQL，Oracle解析时当遇到”,”和”is”时，就忽略了后面的所有hint。在第4条SQL中，this并不是一个关键词，所以append hint有效。基于这个原理，下面的一条SQL中的hint也是不起作用的：

INSERT /*+ NOLOGGING APPEND */ INTO T1 SELECT * FROM T2;

在9.2.0.8和11.2.0.2这2个版本下进行同样的测试，结果完全一样。
为了避免这样的情况，在SQL中书写hint时，在/*+ */和--+这2种结构内只写hint，而不要写逗号，或者是其他的注释。如果要对SQL写注释，在专门的注释结构中写入。比如/* test comment */。如果与hint混写注释，虽然当时没有关键词在里面，但随着版本升级，很可能会加入新的关键词。

另外，一些很常见的hint形式，比如/*+ parallel(t,8) */，/*+ index(t,t_idx) */，虽然当前没有问题，但标准的写法应该是：
/*+ parallel(t 8) */，/*+ index(t t_idx) */

--end end.

DRM引起的问题解决一例

老熊 — Fri, 22 Jul 2011 09:39:17 +0800

客户一套运行在Oracle 10.2.0.5 RAC上的系统，间歇性地出现性能问题。其性能现象为前台反映性能缓慢，从系统上看CPU利用率大幅增加，load增加。这种性能问题通常在出现几分钟后自动恢复正常。

从AWR中的TOP 5等待来看：

Top 5 Timed Events                                         Avg %Total
~~~~~~~~~~~~~~~~~~                                        wait   Call
Event                                 Waits    Time (s)   (ms)   Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
latch: cache buffers lru chain      774,812     140,185    181   29.7      Other
gc buffer busy                    1,356,786      61,708     45   13.1    Cluster
latch: object queue header ope      903,456      55,089     61   11.7      Other
latch: cache buffers chains         360,522      49,016    136   10.4 Concurrenc
gc current grant busy               112,970      19,893    176    4.2    Cluster
          -------------------------------------------------------------

可以看到，TOP 5中，有3个是latch相关的等待，而另外2个则是跟RAC相关的等待。
如果再查看更细的等待数据，可以发现其他问题：


                                                                  Avg
                                            %Time  Total Wait    wait     Waits
Event                                 Waits -outs    Time (s)    (ms)      /txn
---------------------------- -------------- ----- ----------- ------- ---------
latch: cache buffers lru cha        774,812   N/A     140,185     181       1.9
gc buffer busy                    1,356,786     6      61,708      45       3.3
latch: object queue header o        903,456   N/A      55,089      61       2.2
latch: cache buffers chains         360,522   N/A      49,016     136       0.9
gc current grant busy               112,970    25      19,893     176       0.3
gcs drm freeze in enter serv         38,442    97      18,537     482       0.1
gc cr block 2-way                 1,626,280     0      15,742      10       3.9
gc remaster                           6,741    89      12,397    1839       0.0
row cache lock                       52,143     6       9,834     189       0.1

从上面的数据还可以看到，除了TOP 5等待，还有”gcs drm freeze in enter server mode“以及”gc remaster”这2种比较少见的等待事件，从其名称来看，明显与DRM有关。那么这2种等待事件与TOP 5的事件有没有什么关联？。MOS文档”Bug 6960699 - “latch: cache buffers chains” contention/ORA-481/kjfcdrmrfg: SYNC TIMEOUT/ OERI[kjbldrmrpst:!master] [ID 6960699.8]”提及，DRM的确可能会引起大量的”latch: cache buffers chains”、”latch: object queue header operation”等待，虽然文档没有提及，但不排除会引起”latch: cache buffers lru chain“这样的等待。

为了进一步证实性能问题与DRM相关，使用tail -f命令监控LMD后台进程的trace文件。在trace文件中显示开始进行DRM时，查询v$session视图，发现大量的 “latch: cache buffers chains” 、”latch: object queue header operation”等待事件，同时有”gcs drm freeze in enter server mode“和”gc remaster”等待事件，同时系统负载升高，前台反映性能下降。而在DRM完成之后，这些等待消失，系统性能恢复到正常。

看起来，只需要关闭DRM就能避免这个问题。怎么样来关闭/禁止DRM呢？很多MOS文档提到的方法是设置2个隐含参数：

_gc_affinity_time=0
_gc_undo_affinity=FALSE

不幸的是，这2个参数是静态参数，也就是说必须要重启实例才能生效。
实际上可以设置另外2个动态的隐含参数，来达到这个目的。按下面的值设置这2个参数之后，不能完全算是禁止/关闭了DRM，而是从”事实上“关闭了DRM。

_gc_affinity_limit=250
_gc_affinity_minimum=10485760

甚至可以将以上2个参数值设置得更大。这2个参数是立即生效的，在所有的节点上设置这2个参数之后，系统不再进行DRM，经常一段时间的观察，本文描述的性能问题也不再出现。

下面是关闭DRM之后的等待事件数据：

Top 5 Timed Events                                         Avg %Total
~~~~~~~~~~~~~~~~~~                                        wait   Call
Event                                 Waits    Time (s)   (ms)   Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
CPU time                                         15,684          67.5
db file sequential read           1,138,905       5,212      5   22.4   User I/O
gc cr block 2-way                   780,224         285      0    1.2    Cluster
log file sync                       246,580         246      1    1.1     Commit
SQL*Net more data from client       296,657         236      1    1.0    Network
          -------------------------------------------------------------

                                                                  Avg
                                            %Time  Total Wait    wait     Waits
Event                                 Waits -outs    Time (s)    (ms)      /txn
---------------------------- -------------- ----- ----------- ------- ---------
db file sequential read           1,138,905   N/A       5,212       5       3.8
gc cr block 2-way                   780,224   N/A         285       0       2.6
log file sync                       246,580     0         246       1       0.8
SQL*Net more data from clien        296,657   N/A         236       1       1.0
SQL*Net message from dblink          98,833   N/A         218       2       0.3
gc current block 2-way              593,133   N/A         218       0       2.0
gc cr grant 2-way                   530,507   N/A         154       0       1.8
db file scattered read               54,446   N/A         151       3       0.2
kst: async disk IO                    6,502   N/A         107      16       0.0
gc cr multi block request           601,927   N/A         105       0       2.0
SQL*Net more data to client       1,336,225   N/A          91       0       4.5
log file parallel write             306,331   N/A          83       0       1.0
gc current block busy                 6,298   N/A          72      11       0.0
Backup: sbtwrite2                     4,076   N/A          63      16       0.0
gc buffer busy                       17,677     1          54       3       0.1
gc current grant busy                75,075   N/A          54       1       0.3
direct path read                     49,246   N/A          38       1       0.2

那么，这里不得不提的是，什么是DRM？DRM对系统来说有什么好处？本文不再详述，因为下面的2篇文档已经描述得比较清楚，有兴趣的朋友可以参考：

MOS文档：DRM - Dynamic Resource management [ID 390483.1]
Object Remastering In RAC

关于本文所使用的2个隐含参数，在上述第二篇文档中也有详细描述。
--END---

存储过程与DB LINK的依赖关系存在的问题

老熊 — Mon, 04 Jul 2011 23:29:12 +0800

当一个存储过程所依赖（引用的）对象发生某些更改时，会使得存储过程失效（invalidated），比如存储过程依赖（引用）的表增加减少了列、存储过程依赖（引用）的存储过程被重新编译。本文将介绍一种特殊的会引起存储过程失效的情况。

下面通过测试来演示与DB LINK相关的存储过程失效的情况：

1. 在TEST用户下创建到db1的DB LINK：

SQL> create database link to_db connect to perfstat identified by xxx using 'db1';

数据库链接已创建。

2.在TEST2用户下创建到db2的DB LINK，DB LINK的名称仍然为to_db，但实际上连接的数据库与TEST用户下to_db这个DB LINK连接的数据库并不是同一个数据库：

SQL> create database link to_db connect to perfstat identified by xxx using 'db2';

数据库链接已创建。

3. 在TEST用户下创建存储过程TEST_P1：

SQL> create or replace procedure test_p1
  2  is
  3    v_dbid number;
  4  begin
  5    select dbid into v_dbid from stats$snapshot@to_db where rownum<2;
  6  end;
  7  /

过程已创建。

SQL> select object_id,status from user_objects where object_name='TEST_P1';

 OBJECT_ID STATUS
---------- ----------
     18443 VALID

4. 在TEST2用户下创建存储过程TEST2_P1，这里存储过程TEST2_P1的代码与TEST用户下存储过程TEST_P1的代码明显不同。这两个存储过程的共同点是都引用了STATS$SNAPSHOT@TO_DB这个远程表。由于TEST和TEST2用户下TO_DB连接的是不同的数据库，因此这2个存储过程引用的STATS$SNAPSHOT@TO_DB位于不同的数据库上，也就是说是不同的表：

SQL> create or replace procedure test2_p1
  2  is
  3    v_snap_time date;
  4  begin
  5    select snap_time into v_snap_time from stats$snapshot@to_db where rownum<2;
  6  end;
  7  /

过程已创建。

SQL> select object_id,status from user_objects where object_name='TEST2_P1';

 OBJECT_ID STATUS
---------- ----------
     18445 VALID

5. 在TEST用户下查看存储过程TEST_P1的状态，发现其状态为INVALID，而实际上这个时候这个存储过程以及其引用的对象没有任何变更：

SQL> select object_id,status from user_objects where object_name='TEST_P1';

 OBJECT_ID STATUS
---------- ----------
     18443 INVALID

6. 如果重新编译TEST.TEST_P1，那么其状态会成为VALID，但是这个时候TEST2.TEST2_P1则又莫名其妙地变成为INVALID：

SQL> alter procedure test.test_p1 compile;

过程已更改。

SQL> select object_id,owner,object_name,status from dba_objects
  where object_name in ('TEST_P1','TEST2_P1');

 OBJECT_ID OWNER           OBJECT_NAME                    STATUS
---------- --------------- ------------------------------ ----------
     18443 TEST            TEST_P1                        VALID
     18445 TEST2           TEST2_P1                       INVALID

7. 在TEST2用户下执行存储过程TEST2_P1，然后再次检查存储过程状态：

SQL> exec test2_p1

PL/SQL 过程已成功完成。

SQL> select object_id,owner,object_name,status from dba_objects
  2  where object_name in ('TEST_P1','TEST2_P1');

 OBJECT_ID OWNER           OBJECT_NAME                    STATUS
---------- --------------- ------------------------------ ----------
     18443 TEST            TEST_P1                        INVALID
     18445 TEST2           TEST2_P1                       VALID

可以看到，TEST.TEST_P1失效了，而TEST2.TEST2_P1又正常了。

在这里就可以提出问题了：为什么创建了TEST2.TEST2_P1这个存储过程之后，TEST.TEST_P1就失效了？为什么TEST.TEST_P1重新编译之后TEST2.TEST2_P1又失效了？为什么TEST2.TEST2_P1重新执行（有一个隐式的编译过程）后，TEST.TEST_P1又失效了？

其实上以上三个问题可以归纳为一个问题：为什么TEST.TEST_P1和TEST2.TEST2_P1这2个存储过程，在其中一个状态正常的情况下，另一个为失效状态？

此时TEST.TEST_P1这个存储过程是失效状态，那么我们看看这个存储过程引用的哪个对象存在问题：

SQL> select po.obj# p_obj,
  2         po.name p_name,
  3         to_char(p_timestamp, 'DD-MON-YYYY HH24:MI:SS') "P_Timestamp",
  4         to_char(po.stime, 'DD-MON-YYYY HH24:MI:SS') "STIME",
  5         decode(sign(po.stime - p_timestamp), 0, 'SAME', '*DIFFER*') X,
  6         po.status
  7    from sys.obj$ do, sys.dependency$ d, sys.obj$ po
  8   where P_OBJ# = po.obj#(+)
  9     and D_OBJ# = do.obj#
 10     and do.obj# = 18443
 11   order by 2, 1;

     P_OBJ P_NAME                         P_Timestamp               STIME                     X        STATUS
---------- ------------------------------ ------------------------- ------------------------- -------- ------
       648 STANDARD                       18-4月 -2003 00:00:00     18-4月 -2003 00:00:00     SAME       1
     18444 STATS$SNAPSHOT                 25-1月 -2011 18:20:01     26-1月 -2011 11:21:27     *DIFFER*      1
      3217 SYS_STUB_FOR_PURITY_ANALYSIS   15-3月 -2009 17:43:22     15-3月 -2009 17:43:22     SAME       1

SQL> select owner#,name,type#,linkname,remoteowner
  2  from obj$
  3  where obj#=18444;

    OWNER# NAME                 TYPE# LINKNAME             REMOTEOWNER
---------- --------------- ---------- -------------------- ------------
         0 STATS$SNAPSHOT           2 TO_DB                PERFSTAT

在上面的输出中，P_TIMESTAMP是指对象产生依赖关系时所依赖的对象的specification time。STIME指的是依赖对象现在的specification time，二者不一者，说明所依赖对象的specification发生过更改，引起对象的引效。

这里不一致的依赖对象正是PERFSTAT.STATS$SNAPSHOT@TO_DB。我们再看看存储过程TEST2.TEST2_P1的依赖对象：

SQL> select po.obj# p_obj,
  2         po.name p_name,
  3         to_char(p_timestamp, 'DD-MON-YYYY HH24:MI:SS') "P_Timestamp",
  4         to_char(po.stime, 'DD-MON-YYYY HH24:MI:SS') "STIME",
  5         decode(sign(po.stime - p_timestamp), 0, 'SAME', '*DIFFER*') X,
  6         po.status
  7    from sys.obj$ do, sys.dependency$ d, sys.obj$ po
  8   where P_OBJ# = po.obj#(+)
  9     and D_OBJ# = do.obj#
 10     and do.obj# = 18445
 11   order by 2, 1;

     P_OBJ P_NAME                         P_Timestamp               STIME                     X        STATUS
---------- ------------------------------ ------------------------- ------------------------- -------- ------
       648 STANDARD                       18-4月 -2003 00:00:00     18-4月 -2003 00:00:00     SAME       1
     18444 STATS$SNAPSHOT                 26-1月 -2011 11:21:27     26-1月 -2011 11:21:27     SAME       1
      3217 SYS_STUB_FOR_PURITY_ANALYSIS   15-3月 -2009 17:43:22     15-3月 -2009 17:43:22     SAME       1

可以看到TEST2.TEST2_P1这个存储过程同样依赖（引用）object id为18444的对象，也就是PERFSTAT.STATS$SNAPSHOT@TO_DB。也就是说，TEST.TEST_P1和TEST2.TEST2_P2这两个存储过程都依赖于这同一个对象。然而，不幸的是，实际上这两个存储过程所引用的PERFSTAT.STATS$SNAPSHOT@TO_DB对象实际上是不同远程数据库上的对象。这一依赖（引用）对象的唯一标识为REMOTEOWNER, LINKNAME以及NAME，而实际上这三个关键字组合起来并不一定是唯一的。

从面上的数据可以得到，在TEST用户下TO_DB远程库中，PERFSTAT.STATS$SNAPSHOT的specification time为”25-1月 -2011 18:20:01″，而TEST2用户下TO_DB远程库中，PERFSTAT.STATS$SNAPSHOT的specification time为”26-1月 -2011 11:21:27″。当TEST.TEST_P1重新编译时，object id为18444这个对象的specification time（即obj$中的stime列）为”25-1月 -2011 18:20:01″，这样就使TEST2.TEST2_P1的对应依赖对象的时间戳不一致而使其失效。而TEST2.TEST2_P1重新编译后，object id为18444这个对象的specification time（即obj$中的stime列）为”26-1月 -2011 11:21:27″，基于同样的理由，TEST.TEST_P1也失效。

这一问题看上去是Oracle在处理DB LINK远程对象的依赖关系存在缺陷所致。这一问题的触发有如下的条件：不同用户下相同名称的DB LINK连接到不同的数据库，同时这些不同的用户下的存储过程引用了这些DB LINK远程库中的相同用户名下的相同名称的对象。为避免这一问题，不管目前有没有这样的问题，有一个原则：在创建 DB LINK时，连接到不同数据库的DB LINK，其名称不能相同。

实际上在生产环境中，已经数次遇到这样的问题，存储过程和PACKAGE经常失效。在这样的生产环境中，由于数据量和业务量巨大，通常将一套业务系统的数据库按某个规则（比如地域）拆分为多套库，很显然其结构是相同的；而另一套系统的数据库需要通过DB LINK访问已经拆分的多套数据库，而在不同的用户下相同名称的DB LINK指向了不同的数据库，由于本文提及的问题，引起了存储过程和PACKAGE经常失效。

update:
实际上，在MOS文档中也有提及这个问题：
Objects sharing same remote object names(on different databases) and same db link name invalidate each other [ID 270534.1]
Bug 2485372: OBJECTS SHARED SAME REMOTE OBJECT NAME INVALIDATES EACH OTHER
这个BUG从Oracle8i就有了。这个问题至今都没有修复。其解决办法仍然是“同一个数据库中指向不同数据库的DB LINK不能取相同的名字”。
--2011-09-16

shared pool latch和library cache latch

老熊 — Tue, 03 May 2011 14:02:35 +0800

我给《DBA 手记III》投的一篇稿子，名为《一次由隐含参数引起性能问题的处理》，这篇文章描述了一套关键的系统，由于”_kghdsidx_count”这个参数设置为1，导致了严重的性能问题。从故障现象上看是大量的library cache latch的等待，以及shared pool latch的等待，但是前者的等待时间比后者长得多。在文章中，我提到，在当时我推断，由于”_kghdsidx_count”这个隐含参数设置为1，导致shared pool只有1个subpool，引起了shared pool latch的严重竞争，进而引起了library cache cache的更为严重的竞争，这个竞争的过程如下：

由于”_kghdsidx_count”=1，使得shared pool latch只有1个child latch。而library cache latch的child latch数量跟CPU数量有关，最大值为67，编号为child #1-#67。
会话1持有shared pool latch。
会话2解析SQL语句，首先持有了library cache latch的child latch，假设这里为child #1，然后去请求shared pool latch。很显然，这时候被会话1持有，那么会话2就会等待shared pool latch。
会话3解析SQL语句，首先需要请求library cache latch，如果请求的library cache child latch刚好是#1，那么由于会话2持有了这个child latch，就会等待library cache latch。
因此，实际上会话1和会话2的shared pool latch的竞争引起了会话3的library cache latch的等待。如果并发数不是太高，那么shared pool latch的竞争看上去就会比library cache latch的竞争多一些。但是如果有几百个活动会话，这个时候，就会有大量的会话首先等待library cache latch，因为在解析SQL时是首先需要获取library cache latch再获取shared pool latch。由于大量的软解析，甚至不需要获取shared pool latch，同时一个大型的OLTP系统中，某几条相同的SQL并发执行的概率很高，这样会使很多会话同时请求同一library cache child latch；另外，在解析过程中，可能会多次请求library cache latch和shared pool latch，而前者请求和释放的次数会比后者多得多；这样大量的会话在获取library cache latch时处于等待状态，从现象上看就比shared pool latch的等待多得多。

而本文主要表达的是，怎么来验证在解析时，Oracle进程在持有了library cache latch的情况下去请求shared pool latch，而不是在请求shared pool时不需要持有library cache latch。

由于这个验证过程过于internal，所以没有在《DBA手记III》中描述出来。这里写出来，供有兴趣的朋友参考。

验证上面的这一点，有2个方法。下面以测试过程来详细描述。
测试环境：Oracle 10.2.0.5.1 for Linux X86.

方法一：使用oradebug。

1. 将数据库的”_kghdsidx_count”参数值设为1，并重启数据库，以保证只有一个shared pool child latch。
2. 使用sqlplus连接到数据库，假设这个会话是session-1，查询当前的SID:

SQL> select sid from v$mystat where rownum=1;

       SID
----------
       159

同时获得当前连接的spid为2415。
3. 新建一个连接到数据库，假设会话是session-2，查询shared pool latch的地址，并使用oradebug将这个地址对应的值置为1，以表示该latch已经被持有：


SQL> select addr,latch#,level#,child#,name,gets  from v$latch_children where name='shared pool';

ADDR         LATCH#     LEVEL#     CHILD# NAME                                                     GETS
-------- ---------- ---------- ---------- -------------------------------------------------- ----------
200999BC        216          7          1 shared pool                                             34949
20099A20        216          7          2 shared pool                                                 6
20099A84        216          7          3 shared pool                                                 6
20099AE8        216          7          4 shared pool                                                 6
20099B4C        216          7          5 shared pool                                                 6
20099BB0        216          7          6 shared pool                                                 6
20099C14        216          7          7 shared pool                                                 6

SQL> oradebug poke 0x200999BC 4 1
BEFORE: [200999BC, 200999C0) = 00000000
AFTER:  [200999BC, 200999C0) = 00000001

4. 在session-1会话中执行下面的SQL：

SQL> select owner from t where object_id=3003;

正如预料之中的反映，这个会话hang住。

5. 在session-2中，对session-1的进程作process dump。（注意这个时候不能查询v$session_wait、v$latchholder等视图）

SQL> oradebug setospid 2415
Oracle pid: 15, Unix process pid: 2415, image: oracle@xty (TNS V1-V3)
SQL> oradebug dump processstate 10
Statement processed.
SQL> oradebug tracefile_name
/oracle/app/oracle/admin/xty/udump/xty_ora_2415.trc

然后从/oracle/app/oracle/admin/xty/udump/xty_ora_2415.trc这个TRACE文件中可以找到下面的信息：


Process global information:
     process: 0x51a2dce8, call: 0x51b465e4, xact: (nil), curses: 0x51b2a4b8, usrses: 0x51b2a4b8
  ----------------------------------------
  SO: 0x51a2dce8, type: 2, owner: (nil), flag: INIT/-/-/0x00
  (process) Oracle pid=15, calls cur/top: 0x51b465e4/0x51b465e4, flag: (0) -
            int error: 0, call error: 0, sess error: 0, txn error 0
  (post info) last post received: 110 0 4
              last post received-location: kslpsr
              last process to post me: 51a2a904 1 6
              last post sent: 0 0 24
              last post sent-location: ksasnd
              last process posted by me: 51a2a904 1 6
    (latch info) wait_event=0 bits=20
        Location from where call was made: kghupr1: Chunk Header
        Context saved from call: 1306572176
      waiting for 200999bc Child shared pool level=7 child#=1
        Location from where latch is held: kghupr1: Chunk Header
        Context saved from call: 1299065692
        state=busy, wlstate=free
          waiters [orapid (seconds since: put on list, posted, alive check)]:
           10 (54, 1304393092, 54)
           11 (54, 1304393092, 54)
           24 (15, 1304393092, 15)
           15 (6, 1304393092, 6)
           waiter count=4
          gotten 35138 times wait, failed first 502 sleeps 5
          gotten 0 times nowait, failed: 0
      on wait list for 200999bc
      holding    (efd=3) 4f7c75f8 Child library cache level=5 child#=1
        Location from where latch is held: kgllkdl: child: no lock handle: latch
        Context saved from call: 2
        state=busy, wlstate=free

从waiting for 200999bc Child shared pool level=7 child#=1和holding (efd=3) 4f7c75f8 Child library cache level=5 child#=1可以看到，进程的确是在持有了library cache latch的同时去请求 shared pool latch。

最后使用“oradebug poke 0×200999BC 4 0”命令将shared pool latch置为free状态。

方法二：使用gdb。
1. 还原”_kghdsidx_count”参数，重启数据库。
2. 使用sqlplus连接到数据库，获取对应的Oracle Process的spid为4763。
3. 使用gdb：

[oracle@xty ~]$ gdb -p 4763
GNU gdb (GDB) Red Hat Enterprise Linux (7.0.1-23.el5)
Copyright (C) 2009 Free Software Foundation, Inc.
...省略部分输出...
Reading symbols from /lib/libnss_files.so.2...(no debugging symbols found)...done.
Loaded symbols for /lib/libnss_files.so.2
0x0059b402 in __kernel_vsyscall ()

4. 在gdb中，在latch的获取和释放的函数上设置断点：

(gdb) b kslgpl
Breakpoint 1 at 0x8339fca
(gdb) b kslgetsl
Breakpoint 2 at 0x833a2d5
(gdb) b kslgpl
Breakpoint 3 at 0x83473bf
(gdb) b kslg2c
Breakpoint 4 at 0x8347886
(gdb) b kslg2csl
Breakpoint 5 at 0x834794e
(gdb) b kslgprl
Breakpoint 6 at 0x8346186
(gdb)
Note: breakpoint 6 also set at pc 0x8346186.
Breakpoint 7 at 0x8346186
(gdb) b kslfre
Breakpoint 8 at 0x833c05d
(gdb) b kslf2c
Breakpoint 9 at 0x8347a1e
(gdb) b kslfpl
Breakpoint 10 at 0x8347812
(gdb) b kslfal
Breakpoint 11 at 0x833fbca
(gdb) b kslfpl0
Breakpoint 12 at 0x834766d
(gdb)
注：最后几个函数只是猜测跟latch有关....latch的请求和释放所调用的函数主要为：kslgetl、kslgetsl和kslfre。
(gdb) c
Continuing.

5. 在sqlplus中执行SQL：

SQL> select * from t where object_id=10000;

正如预期的那样，会话hang住。这是因为运行到了gdb设置的断点。

6.在gdb中可以看到：

Breakpoint 2, 0x0833a2d5 in kslgetsl ()
(gdb) info f
Stack level 0, frame at 0xbfd3fb08:
 eip = 0x833a2d5 in kslgetsl; saved eip 0x84257e1
 called by frame at 0xbfd3fb44
 Arglist at 0xbfd3fb00, args:
 Locals at 0xbfd3fb00, Previous frame's sp is 0xbfd3fb08
 Saved registers:
  ebp at 0xbfd3fb00, eip at 0xbfd3fb04
(gdb) x /10x 0xbfd3fb00
0xbfd3fb00:     0xbfd3fb3c      0x084257e1      0x51b4c38c      0x00000001
0xbfd3fb10:     0x51b11738      0x00000058      0x00000008      0x00000002
0xbfd3fb20:     0x0d099c40      0x0d099d3c

0×51b4c38c这是一个地址，从v$latch和v$latch_children中可以查到正是是 session idle bit latch。

6.在gdb中继续：

(gdb) c
Continuing.

Breakpoint 8, 0x0833c05d in kslfre ()
(gdb) info f
Stack level 0, frame at 0xbfd3fb18:
 eip = 0x833c05d in kslfre; saved eip 0x842581a
 called by frame at 0xbfd3fb44
 Arglist at 0xbfd3fb10, args:
 Locals at 0xbfd3fb10, Previous frame's sp is 0xbfd3fb18
 Saved registers:
  ebp at 0xbfd3fb10, eip at 0xbfd3fb14
(gdb) x /10x 0xbfd3fb10
0xbfd3fb10:     0xbfd3fb3c      0x0842581a      0x51b4c38c      0x00000002
0xbfd3fb20:     0x0d099c40      0x0d099d3c      0x0d099c40      0x00000002
0xbfd3fb30:     0x00000000      0x517a7090
(gdb) c
Continuing.
----下面很重要-----
Breakpoint 1, 0x08339fca in kslgetl ()
(gdb) x /10x $ebp+8
0xbfd3ecc0:     0x4f7c7594      0x00000001      0x00000001      0x00000a57
0xbfd3ecd0:     0x0af275ca      0x00000000      0x0dcfdcc0      0x0d045860
0xbfd3ece0:     0xbfd3ed58      0x0b20fc09
(gdb) c
Continuing.

Breakpoint 8, 0x0833c05d in kslfre ()
(gdb) x /10x $ebp+8
0xbfd3ed64:     0x4f7c7594      0x00000000      0x10010040      0x0d045860
0xbfd3ed74:     0xbfd3ef10      0x0b1f5d10      0x0d099c40      0x4f7c7594
0xbfd3ed84:     0x00000000      0x00000008
(gdb) c
Continuing.

Breakpoint 1, 0x08339fca in kslgetl ()
(gdb) x /10x $ebp+8
0xbfd3ecc0:     0x4f7c7594      0x00000001      0x00000001      0x00000a57
0xbfd3ecd0:     0x0af275ca      0x00000000      0x0dcfdcc0      0x0d045860
0xbfd3ece0:     0xbfd3ed58      0x0b20fc09
(gdb) c
Continuing.

Breakpoint 1, 0x08339fca in kslgetl ()
(gdb)  x /10x $ebp+8
0xbfd3eb50:     0x200999bc      0x00000001      0x00000000      0x000009de
0xbfd3eb60:     0x0d099c40      0x0000000f      0x0c3c3ec0      0x0d045860
0xbfd3eb70:     0xbfd3ec10      0x0af3983b
(gdb) c
Continuing.

Breakpoint 8, 0x0833c05d in kslfre ()
(gdb)  x /10x $ebp+8
0xbfd3eb6c:     0x200999bc      0x0d099c40      0x2001d310      0x0d045860
0xbfd3eb7c:     0xbfd3ec10      0x0af390a8      0x0d099c40      0x200999bc
0xbfd3eb8c:     0xbfd3ebe8      0x00000164
(gdb) c
Continuing.

Breakpoint 8, 0x0833c05d in kslfre ()
(gdb)  x /10x $ebp+8
0xbfd3ed64:     0x4f7c7594      0x00000000      0x10010040      0x0d045860
0xbfd3ed74:     0xbfd3ef10      0x0b1f58e6      0x0d099c40      0x4f7c7594
0xbfd3ed84:     0x00000000      0x00000008
(gdb) quit
A debugging session is active.

        Inferior 1 [process 4763] will be detached.

同时可以从数据库中查到：

SQL> select addr,latch#,child#,level#,name from v$latch_children
where name in ('library cache','shared pool');
ADDR         LATCH#     CHILD#     LEVEL# NAME
-------- ---------- ---------- ---------- --------------------------------------------------
4F7C75F8        217          1          5 library cache
4F7C7594        217          2          5 library cache
4F7C7530        217          3          5 library cache
200999BC        216          1          7 shared pool
20099A20        216          2          7 shared pool
20099A84        216          3          7 shared pool
20099AE8        216          4          7 shared pool
20099B4C        216          5          7 shared pool
20099BB0        216          6          7 shared pool
20099C14        216          7          7 shared pool

标记为”下面很重要“的输出，汇总起来就是：

kslgetl  0x4f7c7594  library cache
kslfre   0x4f7c7594  library cache
kslgetl  0x4f7c7594  library cache
kslgetl  0x200999bc  shared pool
kslfre   0x200999bc  shared pool
kslfre   0x4f7c7594  library cache

这个过程可以理解为：Oracle进程首先获取library cache latch，在library cache中查找是否已经有要执行的SQL语句（这里显然没有找到），然后释放library cache。接下来是硬解析SQL的后半部分，首先获取library cache latch，然后获取shared pool latch，从shared pool中申请内存，然后释放shared pool latch，最后再获取library cache latch。

后面不再继续跟踪解析的过程，这个过程会有相当多的latch的获取和释放，但是从上面可以很清晰地看到，进程在持有了library cache latch的同时去请求shared pool latch。

至于这个案例，大家会在《DBA 手记III》上看到完整的介绍。

ORA-04031案例一则

老熊 — Fri, 29 Apr 2011 18:12:51 +0800

ORA-04031这个错误，几乎每一个专业的DBA都遇到过。这是一个相当严重的错误，Oracle进程在向SGA申请内存时，如果申请失败，则会报这个错误。大部分情况下是在向SGA中的shared pool申请内存时失败，而少有向large pool等池中申请内存失败。比如下面的报错：

Wed Apr 27 16:00:25 2011
Errors in file /oracle/app/oracle/admin/zxin/bdump/zxin1_ora_2052294.trc:
ORA-04031: unable to allocate 4128 bytes of shared memory
("shared pool","unknown object","sga heap(3,0)","kgllk hash table")

这里很清楚地表示出来，是在向shared pool申请内存时失败。

shared pool内存申请（分配）失败，通常有如下的几种可能：

shared pool过小，比如在SGA Manual Management方式下，shared pool设置过小。比如一套数千连接的大系统，shared pool只设置了几百M。这种情况下，要解决问题很解单，增加shared pool的大小即可。
应用没有使用绑定变量，硬解析非常多，导致shared pool内存碎片严重，分配大块内存时不能获得连续的内存空间。硬解析多的一个变种是虽然使用了绑定变量，但是由于某种原因，Cursor不能共享，导致Child Cursor非常多。实际上，如果shared pool较大（比如数GB大小），这种问题还是很少出现的，并且出现也通常出现在申请大块内存时。这种情况如果使用alter system flush shared_pool可以暂时缓解问题。但是这条命令又通常不适用于shared pool较大而且比较繁忙的系统。使用绑定变量
Cache的cursor很多，同时cursor_space_for_time这一参数设置为TRUE，可能会使shared pool碎片化严重，导致不能分配到大块的连续内存。
Oracle的BUG导致内存泄露，比如在一些版本中查询v$segment_statistics这样的视图导致内存泄露，使shared pool内存耗光。同样的情形还有类似于“obj stat memory”,”gcs resources”,”ges resources”等。通常这类内存为perm类型（permanet），这类内存通常是在分配时就确定了固定的用途，不能用于其他用途，因此极容易产生碎片。
Oracle从9i开始，根据shared pool的大小将shared pool分为多个子池（subpool)，每个子池有独立的free list，同时在分配时单独管理（有其独立的shared pool latch）。Oracle的BUG或者说是内存分配策略缺陷导致某一类shared pool的内存分配只在一个子池(subpool)中，即多个子池的使用极不均衡，导致向那个使用得最多的子池申请内存时失败。报错信息中的”sga heap(3,0)”即指明是在第3个子池申请内存时失败。本文案例中的ORA-04031错误其产生的原因可以归结为Oracle对shared pool的分配/使用策略问题。
操作系统内存不足，这只会出现在shared pool的使用还没有达到最大值时才会出现，并且在操作系统都有swap的情况下，只有部分操作系统才可能有这种情况，比如在HP-UX下，reserved 内存过多导致swap满。
其他原因，多数是因为BUG。请参考下面提及的MOS参考文档。

本文中的案例，其数据库是运行在AIX 5.3系统中的10.2.0.4 RAC，RAC节点数为2。数据库是从9i升级到10g，而目前处于正式升级前的测试阶段。数据库报的ORA-04031错误信息如本文前面所示（其中的数据库名称已经做了处理）。

在继续讲解案例之前，不得不提到MOS上的几篇关于ORA-04031错误的文档：

Master Note for Diagnosing ORA-4031 [ID 1088239.1]
Diagnosing and Resolving Error ORA-04031 on the Shared Pool or Other Memory Pools [Video] [ID 146599.1]
Interpreting the automatically generated ORA-4031 diagnostic trace. [ID 809560.1]
Troubleshooting and Diagnosing ORA-4031 Error [Video] [ID 396940.1]
ORA-4031 Common Analysis/Diagnostic Scripts [Video] [ID 430473.1]

其实分析ORA-04031错误，通常有以下几个要点：

判断错误发生所有的内存区域，是shared pool,large pool还是streams pool等。这个很容易从错误信息中判断出来，本文主要描述shared pool的ORA-04031错误，这也是最常见的。
检查Shared Pool的总大小以及free memory的大小。如果free memory看上去挺多，以subpool为单位检查是否存在是由于碎片导致没有足够的连续内存以供分配，特别是关注报错信息中提及的子池。
如果Shared Pool相较于系统规模来说足够大（通常数GB都已经是很大的了），检查Shared Pool中有没有占用非常多的内存类型或内存组件，如果有，是什么样的类型的内存，在各个子池之间是否分布均匀。如果有异常占用较多的内存类型，根据此类型在MOS上搜寻是否是会有相应的BUG引起，或者分析这种类型的内存消耗较多的原因。比如如果是sql area很大，检查是不是硬解析特别多，或者是不是child cursor特别多引起。
基于以上分析的数据，来判断shared pool内存分配失败的原因。

上面的步骤写得比较粗略，关于分析和解决ORA-04031问题，这里也有一篇不错的文章：Simplified Approach to Resolve ORA-4031

这里关键的是分析Shared Pool的内存数据。ORA-04031错误发生后如果有条件可以马上连接到数据库中查询相应的x$表和v$视图得到相应的数据，否则只能通过ORA-4031错误发生时产生的trace文件。_4031_dump_bitvec这个隐含参数用于控制发生ORA-04031错误时对SGA的dump行为，而trace文件的分析就不像使用SQL那样简单了。

下面再来详细地分析案例：
从错误信息来看，很显然，是向shared pool的第3个subpool申请内存时出错。
以下的数据是shared pool的数据：

SQL> select sum(bytes)/1024/1024 mb from v$sgastat where pool='shared pool';

        MB
----------
4096.53062

SQL> SELECT KSMCHCLS CLASS, COUNT(KSMCHCLS) NUM, SUM(KSMCHSIZ)
  2  SIZ,
  3  To_char( ((SUM(KSMCHSIZ)/COUNT(KSMCHCLS)/1024)),'999,999.00')|
  4  |'k' "AVG SIZE"
  5  FROM X$KSMSP GROUP BY KSMCHCLS; 

CLASS           NUM        SIZ AVG SIZE
-------- ---------- ---------- ------------
R-freea         512      24576         .05k
freeabl      807395 1643969848        1.99k
recr         530728  662065240        1.22k
R-free          256  214910976      819.82k
free          43063  100605496        2.28k
perm            140 1673368632   11,672.49k

虽然free的数量不是太多，但是freeable的数量还是很多的。
下面是各个子池更详细的数据：

SQL> SELECT KSMCHIDX,KSMCHDUR, KSMCHCLS CLASS, COUNT(KSMCHCLS) NUM, SUM(KSMCHSIZ)
  2  SIZ,
  3  To_char( ((SUM(KSMCHSIZ)/COUNT(KSMCHCLS)/1024)),'999,999.00')|
  4  |'k' "AVG SIZE"
  5  FROM X$KSMSP GROUP BY KSMCHIDX,KSMCHDUR, KSMCHCLS
  6  order by 1,2,3; 

  KSMCHIDX   KSMCHDUR CLASS           NUM        SIZ AVG SIZE
---------- ---------- -------- ---------- ---------- ------------
         1          1 R-free           27   22666392      819.82k
                      R-freea          54       2592         .05k
                      free             26      14024         .53k
                      perm             32  430299448   13,131.70k
                    2 R-free           12   10073952      819.82k
                      R-freea          24       1152         .05k
                      free          10531   24519112        2.27k
                      freeabl       44922   32457736         .71k
                      recr         163177  134273584         .80k
                    3 R-free            9    7555464      819.82k
                      R-freea          18        864         .05k
                      free           1678    4555704        2.65k
                      freeabl       79815  102514024        1.25k
                      recr          32689   36368096        1.09k
                    4 R-free           20   16789920      819.82k
                      R-freea          40       1920         .05k
                      free           2182    5810056        2.60k
                      freeabl       66235  254656184        3.75k
                      recr          16245   58284480        3.50k
         2          1 R-free           25   20987400      819.82k
                      R-freea          50       2400         .05k
                      free             23      20016         .85k
                      perm             35  398418384   11,116.58k
                    2 R-free            4    3357984      819.82k
                      R-freea           8        384         .05k
                      free           5137    6604176        1.26k
                      freeabl       40377   12140944         .29k
                      recr          54942   45005024         .80k
                    3 R-free            9    7555464      819.82k
                      R-freea          18        864         .05k
                      free           1477    5524568        3.65k
                      freeabl       79548  101879808        1.25k
                      recr          32380   36033448        1.09k
                    4 R-free           21   17629416      819.82k
                      R-freea          42       2016         .05k
                      free           2540    7092424        2.73k
                      freeabl       70133  270332800        3.76k
                      recr          15924   57263032        3.51k
         3          1 R-free           26   21826896      819.82k
                      R-freea          52       2496         .05k
                      free             26      20520         .77k
                      perm             33  414355416   12,261.94k
                    2 R-free            4    3357984      819.82k
                      R-freea           8        384         .05k
                      free           4693    7053032        1.47k
                      freeabl       49723   14339800         .28k
                      recr          52771   42357312         .78k
                    3 R-free           11    9234456      819.82k
                      R-freea          22       1056         .05k
                      free           3594    9280904        2.52k
                      freeabl       95823  121934488        1.24k
                      recr          39643   44097504        1.09k
                    4 R-free           25   20987400      819.82k
                      R-freea          50       2400         .05k
                      free           2822    7291680        2.52k
                      freeabl       84443  323149712        3.74k
                      recr          19148   67997008        3.47k
         4          1 R-free           27   22666392      819.82k
                      R-freea          54       2592         .05k
                      free             26      18088         .68k
                      perm             40  430295384   10,505.26k
                    2 R-free            6    5036976      819.82k
                      R-freea          12        576         .05k
                      free           4818   11473920        2.33k
                      freeabl       46089   39963224         .85k
                      recr          54061   44188072         .80k
                    3 R-free            9    7555464      819.82k
                      R-freea          18        864         .05k
                      free           1427    4109504        2.81k
                      freeabl       80026  102379080        1.25k
                      recr          33217   36949240        1.09k
                    4 R-free           21   17629416      819.82k
                      R-freea          42       2016         .05k
                      free           1993    6228464        3.05k
                      freeabl       70581  269087136        3.72k
                      recr          16614   59372656        3.49k

KSMCHDUR是什么意思？在9i里面这个列的值通常为1。实际上，Oracle从9i开始，将shared pool划分为多个sub pool。而在10g以上的版本中（具体开始的版本号已经不记得），每个sub pool又分了4个更小的池，我们暂且称之为mini heap。每个mini heap有其自己的free list。KSMCHDUR这一列即表示mini heap的编号。”heap(3,0)”中的0是指第1个mini heap。

在上面的数据中，可以看到这个子池的第1个mini heap的free已经很少，只有10来K。另外，我们可以观察到，perm类型的内存块只存在于每个sub pool的第1个min heap中。这个是一个重点，在后面会有解释。

这里本应该有通过查询v$sgastat得到shared pool的各个组件占用的内存分布，只是写BLOG时找不到了….但是我们可以在trace文件中找到数据，下面只列出sub pool 3的数据：

==============================
Memory Utilization of Subpool 3
================================
     Allocation Name          Size
_________________________  __________
"free memory              "    81466568
"miscellaneous            "           0
"dpslut_kfdsg             "         512
"trace buffer             "      737280
"trace_knlasg             "         504
"gcs res hash bucket      "     1048576
"gcs res latch table      "       12288
"evaluation con           "           0
"sql area                 "   344545752
"UNDO STAT INFO           "       59904
"txncallback              "      141744
"transaction              "     2103264
"ges resource pools       "        3968
"sessions                 "     4526488
"dlo fib struct           "      128032
"KJCTS process batching st"         240
"row cache                "        3272
"KCB where statistics arra"       25888
"KCB buffer wait statistic"       32000
"KCB incremental ckpt entr"         512
"invalid low rba queue    "        1024
"table definiti           "      108704
"temporary tabl           "        4136
"KCL instance cache transf"      131072
"resumable                "        2720
"KESTB existence bitvec se"         128
"type object de           "      392448
"enqueue_hash             "      318960
"KSXR pending consumption "       20192
"KTI SGA freeable small po"           0
"trigger defini           "      885472
"trigger source           "       99264
"trigger inform           "         960
"KTCN: Obj Invalidation Se"        2336
"kmgsb circular statistics"      108800
"kgl lock hash table state"       45360
"kglsim size of pinned mem"        8024
"kelr system metrics table"         280
"kzctxgjsi ksuseclid memor"      117360
"kzctxgjci ksuseclid  memo"           0
"CCursor                  "    95912048
"ksr message pool free que"      188960
"ksb ci process list (each"         144
"ksunfy: nodes of hierarch"         320
"ksuloi: long op free list"         256
"kwqmncal: allocate buffer"        4048
"ksim group query request "           0
"ksuxds ksuseclid  memory "           0
"call                     "       87304
"dictionary cache         "           0
"KSXR pending reply queue "      255488
"hng: All sessions data fo"           0
"ksfv subheap descriptor  "         184
"gcs resources            "   169082312
"gcs affinity             "        8320
"gcs opaque in            "       12312
"PCursor                  "    50743128
"ges resource             "      539376
"fdrec_kffsg              "          24
"work area tab            "       80640
"kglsim main lru count    "       38400
"plwpil:wa                "        4264
"grptab_kfgsg             "        2464
"AW SGA                   "          40
"KEWS sesstat seg tbl     "           8
"kebm slave descriptors   "        1456
"kglsim hash table bkts   "     1048576
"KSXR global channels     "        1288
"ges enqueues             "    17333720
"PLS chunk                "         352
"KSQ event description    "        1440
"KESTB existence bitvec   "        4096
"gcs shadows              "   101246344
"qmtb_init_data           "         224
"Core dump directory      "         264
"sort segment handle      "        7480
"SERVICE NAME ENTRY       "          48
"PQ/BizCard               "        1536
"qtree_kwqbspse           "          40
"latch descriptor table   "        1576
"recovery domain          "       29856
"parameters               "       30056
"SHARED SERVERS INFO      "         240
"qtree_kwqbsgn            "          40
"post agent               "           0
"pspool_kfsg              "          80
"plwsppwp:wa              "           0
"PL/SQL DIANA             "    14050624
"segmented arrays         "        2072
"Checkpoint queue         "     4097024
"sim lru segments         "        2560
"sim segment hits         "        2560
"sim state object         "          40
"partitioning d           "      199616
"ASH buffers              "     8388608
"message pool freequeue   "      276336
"PL/SQL MPCODE            "     4499360
"PL/SQL PPCODE            "     3984944
"procs: ksunfy            "     1512000
"primem_kfmdsg            "        1032
"SYSTEM PARAMETERS        "       76624
"object queue hash buckets"      262656
"object queue hash table d"        7552
"object level stats hash t"         512
"object stat dummy statprv"         144
"sim cache sizes          "         320
"logout storm management  "       24000
"pl/sql source            "       21256
"sys event stats          "      199136
"parameter handle         "       67896
"Parameter Handle         "        1656
"channel handle           "      828672
"API blockers array       "          64
"PARAMETER TABLE          "        2048
"PARAMETER ENTRY          "           8
"LGWR post requested array"          24
"bloom filter             "        3104
"param hash values        "        5984
"sql area:PLSQL           "    11477776
"PX subheap desc          "         256
"repository               "      213544
"sql area:KOKA            "       16192
"archive_lag_target       "        9624
"state objects            "         640
"latch nowait fails or sle"      116832
"sched job slv            "        5952
"pso tbs: ksunfy          "      390000
"dummy                    "      269928
"Sort Segment             "       37440
"Cursor Stats             "     6095760
"Banner Storage           "        2048
"quiescing session        "        3872
"API data buffer          "          16
"buffer handles           "     1020000
"prmtzdini tz region      "      408320
"sga node map             "          16
"savepoints               "           0
"Managed Standby Proc Arra"       24576
"OS proc request holder   "        4664
"db_files                 "      416576
"PX server msg stats      "        2288
"KQR M PO                 "      283376
"kks stats                "          40
"parameter table block    "      483168
"KSFV SGA                 "         824
"plugin datafile array    "       36016
"plwda:PLW_STR_NEW_RVAL   "          24
"plwspv:PLW_STR_NEW_VAL   "          16
"KGKP sga                 "          32
"BRANCH TABLE SEGMENTED AR"       70176
"mvobj part des           "      306544
"parameter value memory   "         216
"multiblock re            "       98496
"parameter text value     "        1080
"parallel_max_servers     "        8192
"KGLS heap                "    13290800
"KGSKI sga                "          80
"resize request state obje"      368000
"MTTR advisory            "     1462832
"monitoring co            "       12480
"rules engine aggregate st"        1416
"krbmror                  "       36400
"joxs heap                "         136
"krbmrsr                  "         152
"ksfqpar                  "        4008
"SGA - SWRF DrvMet Runtime"        2656
"SGA - SWRF Metrics ksuTim"          72
"SGA - SWRF RawMet Runtime"        1408
"SGA - SWRF Metrics WCTime"          32
"SQL Memory Manager Base W"       13400
"change notification regis"        4096
"simulator latch/bucket st"       59392
"Prefetch history buffer  "        2832
"change notification obj m"        4096
"KQR ENQ                  "       16512
"kksss                    "       16464
"API data buffer length   "           0
"kokcd                    "           0
"kohsg                    "           8
"Sequence Background Insta"          88
"ksfqpn                   "         416
"KGLS SP                  "        4704
"knstsg                   "          48
"latch classes            "         352
"system default language h"         568
"name-service entry       "        2592
"API data buffer array    "           0
"kzull                    "        4096
"kzulu                    "         392
"kfgsga                   "         104
"library cache            "    46604712
"kcrrny                   "       25320
"spfile cleanup structure "       16760
"xssinfo                  "        5952
"buffer_pool_desc_array   "        3384
"row cache child latch    "        3360
"rm request queue link    "        5320
"SCHEDULING POLICY TABLE  "         160
"namhsh_kfdsg             "        4104
"Closed Thread SCN Bitvec "        8448
"Client ID trace settings "        3872
"osp allocation           "       21104
"os statistics            "        9192
"plwppwp:PLW_STR_NEW_LEN_V"          16
"plwgc: plwgc_garbage_clea"           0
"plwiiw: kglpql warnings  "           0
"object queue             "      808080
"obj stat memo            "      599184
"obj htab chun            "      122960
"object level             "      111888
"XCT XGA                  "           0
"SGA - SWRF Metric Eidbuf "      900840
"Processor group descripto"          64
"Prefetch client count per"          32
"X$SKGXPIA                "        2680
"simulator hash buckets   "     2101248
"State object subpools    "         896
"API data buffer length ma"           0
"AWR Table Info (KEW layer"         872
"character set memory     "        4856
"sim segment num bufs     "        1280
"character set object     "      129728
"session idle latches     "        2560
"qesmmaInitialize:        "         112
"returns from remote ops  "       49152
"name-service             "        4080
"SGA - SWRF Metric CHBs   "       10912
"listener addresses       "          32
"db_block_hash_buckets    "    67108864
"KSI resource types       "        2704
"kglsim object batch      "     4196304
"trigger condition node   "          72
"ksws service events      "       18560
"Heap0: KGL               "    11642128
"fixed allocation callback"         392
"kqlpWrntoStr:value       "           0
"KEWS statistic name      "         424
"KEWS statistic maps      "        1096
"KCL partition table      "      131072
"kebm slave message       "          88
"kcbl state objects       "       12800
"free rm request queue lin"           0
"xsoqsehift               "        3104
"DBWR event stats array   "         192
"kgllk hash table         "      659456
"event descriptor table   "         192
"kpssnfy: kpsssgct        "          32
"kpscad: kpscscon         "        1952
"dbwriter coalesce buffer "     3158016
"kglsim hash table        "        8208
"gcs resource freelist dyn"         256
"gcs shadow locks dyn seg "         256
"kks stats latch          "         160
"KTC latch cleanup        "         576
"ges enqueue max. usage pe"          64
"ges lmd process descripto"        2760
"KTU latch cleanup        "        2496
"kscdnfyinithead          "          16
"X$KSVIT table            "         512
"kqlpaac:value-1          "          64
"KCL buffer header        "      192064
"kxfpdp pointers          "       28800
"kodosgi kopfdo           "         104
"kglsim latches           "         136
"TXN TABLE SEGMENTED ARRAY"       54784
"KJCT remote i            "        1640
"KKJ SHRD WRQS            "         288
"KJC dest ctx             "        3560
"kwrsnfy: kwrs            "        1624
"kwqmn:tskdata            "           0
"KKKI consumer            "        4136
"dbwr suspend/resume ptr a"          16
"dbwr actual working sets "          64
"KGSKI schedule           "           0
"temp lob duration state o"        3296
"ges regular msg buffers  "     3078008
"jsksncb: 9               "       28672
"Transportable DB Converte"        2552
"KTU lat struct           "         800
"kks stats hds            "         256
"KSFD SGA I/O b           "     4190248
"HTTP fixed headers       "          72
"UNDO INFO SEGMENTED ARRAY"      649856
"ges process hash table   "      132000
"jsksncb-latch            "        1280
"kfkid hrec               "          24
"KTCCC OBJECT             "           0
"KTPR HIST TB             "        2808
"KTF MAPPINGS             "       12288
"kksss-heap               "       35136
"kglsim heap              "     3431232
"event statistics per sess"     7665280
"eventlist to post commits"          16

从上面的数据可以看到，第3个sub pool中，占用较多的内存是gcs resources、gcs shadows以及sql area。但是没有明显的异常。
下面是第3个sub pool中第1个mini-heap中free memory的更详细数据：

SQL> break on ksmchidx on ksmchdur
SQL> select
  2    ksmchidx,ksmchdur,
  3    case
  4          when ksmchsiz < 1672 then trunc((ksmchsiz-32)/8)
  5          when ksmchsiz < 4120 then trunc((ksmchsiz+7928)/48)
  6          when ksmchsiz < 8216 then 250
  7          when ksmchsiz < 16408 then 251
  8          when ksmchsiz < 32792 then 252
  9          when ksmchsiz < 65560 then 253
 10          when ksmchsiz >= 65560 then 253
 11     end bucket,
 12    sum(ksmchsiz)  free_space,
 13    count(*)  free_chunks,
 14    trunc(avg(ksmchsiz))  average_size,
 15    max(ksmchsiz)  biggest
 16  from
 17    sys.x$ksmsp
 18  where
 19    inst_id = userenv('Instance') and
 20    ksmchcls = 'free'
 21  group by
 22    case
 23          when ksmchsiz < 1672 then trunc((ksmchsiz-32)/8)
 24          when ksmchsiz < 4120 then trunc((ksmchsiz+7928)/48)
 25          when ksmchsiz < 8216 then 250
 26          when ksmchsiz < 16408 then 251
 27          when ksmchsiz < 32792 then 252
 28          when ksmchsiz < 65560 then 253
 29          when ksmchsiz >= 65560 then 253
 30     end ,
 31    ksmchidx, ksmchdur
 32  order by ksmchidx , ksmchdur
 33  /

  KSMCHIDX   KSMCHDUR     BUCKET FREE_SPACE FREE_CHUNKS AVERAGE_SIZE    BIGGEST
---------- ---------- ---------- ---------- ----------- ------------ ----------
         3          1          5         72           1           72         72
                              13        136           1          136        136
                              27        248           1          248        248
                              48        416           1          416        416
                              56       1920           4          480        480
                              66       1680           3          560        560
                              68       4608           8          576        576
                             164       1344           1         1344       1344
                             180       1472           1         1472       1472
                             188       1536           1         1536       1536
                             190       1552           1         1552       1552
                             199       1624           1         1624       1624
                             204       1880           1         1880       1880
                             207       2032           1         2032       2032

可以看到，最大的free memory块才2032字节，而报错中提到的申请的内存大小为4128字节。由于在第3个sub pool的第1个mini heap中没有4128字节的连续free memory，所以导致内存申请失败。

那么这里的问题是，为什么这个mini heap中的free memory那么少？正如前面提及，为什么这个mini heap中的已经使用的类型全是perm类型？这个问题的答案就在于”DURATION”。Oracle在启用了SGA自动管理的模式下，为了便于在shared pool与buffer cache或其他内存之间动态调整大小，规定了在每一个mini heap中分配内存按照duration来进行。这里duration可以理解为内存块的持久时间。perm类型的内存块，就是分配后不能释放，只能用于相同组件的重用。比如gcs resources这种组件的内存是perm类型，这种内存被分配后，不能释放给sql area使用，也不能给gcs shadows使用，只能给其他的gcs resource使用。按DURATION分配内存时，perm类型的内存就只能从每个sub pool的第1个mini heap中分配。而其他类型的内存通常在sub pool的第2-4个mini heap中分配。由于perm类型的内存不能释放，也不能被其他组件的内存重用，所以里面的内存会越用越少，如果没有了free memory怎么办？前面说到，这种模式主要是工作在SGA自动管理模式下，如果free memory没有了，就会从SGA中的其他部分，比如buffer cache中取得memory chunk，加入到缺少内存的mini heap中。正常情况下这种机制没有问题。

完全使用SGA自动管理有一个缺陷就是，如果应用系统绑定变量做得不好，或者由于BUG，child cursor过多，导致shared pool会变得很大，甚至超过10G，严重的比buffer cache还大，另一方面，在buffer cache和shared pool之间频繁地调整大小，可能会导致严重的解析问题和其他性能问题。针对这个问题，通常有2种解决办法：一种就是关闭SGA自动管理，即将SGA_TARGET设置为0，以9i的方式来设置shared_pool_size,db_cache_size这些参数，来手动管理SGA；第二种就是sga_target仍然大于0，即自动管理SGA，但是通过设置shared_pool_size，db_cache_size等参数限制这些内存组件的最小大小，而只留给系统极少的自动调整空间。

而出现问题的这套系统，正是使用了第二种方式，开启了SGA自动调整，但是留给自动调整的空间极少。SGA_TARGET为35G，buffer_cache_size为30G，shared_pool_size为4G，再加上large_pool等组件，几乎没有什么可自动调整的余地。这种方式下，就存在了问题。下面来做一个按时间的分析：

时间T1，数据库启动，shared pool只消耗了极少量的内存。
时间T2至时间T3，Oracle进程请求shared pool内存，Oracle会向操作系统以指定的粒度为单位（比如16MB）请求物理内存，加入到所请求内存所在的mini heap中。直至shared pool的大小达到shared pool最大容许的大小。这个容许大小由各参数计算而来。比如说SGA_TARGET为10G，其他组件的参数设置后最小值为8G，shared_pool_size的值为1G，但是shared pool的最大容许大小为2G。这个时候，每个sub pool的mini heap的大小已经固定。在到达shared pool最大容许大小这一阶段，可能会从buffer cache等组件中占用。
时间T4，Oracle进程请求shared pool内存，这个时候只能从free list或age out内存块后获取内存，对于sub pool的第1个mini heap，只能从free list中获取，因为这个mini heap中的已用内存全是perm，是不能age out的。
时间T5，Oracle进程请求shared sub pool中第1个mini heap的内存，但是free list中已经没有内存。所以报ORA-04031错误。

在上面的时间点T5那里，如果SGA有较大的自动调整空间，比如说完全没有限制，即buffer_cache_size等参数很少或为0，这样在请求第1个mini heap中的内存时，完全可以从buffer cache中占用，这样的后果是使shared pool越来越大。

而本文案例的ORA-04031，正是由于SGA自动管理，而自动调整的余地又太小，最终使sub pool的第1个mini heap空间用光。当然我们可以分析为什么会用光，这个就显得更为复杂，这跟数据量、应用系统都有很大的关系。而系统中第1次出现ORA-04031错误的进程，是一个job进程，而此后大部分出现的错误均是job进程，能检查job代码，发现在做大量的表的大量数据的UPDATE操作，这可能是引起gcs shadows和gcs resources大量内存使用的原因。在一套RAC数据库中，gcs和ges相关的perm内存占用可能会比较大。

那么除了调整应用，应该怎么样解决这样问题？这里的解决方法是增加shared_pool_size参数到6G，同时将sga_target设置为0，再重启。
而另一种可能的办法是将参数“_enable_shared_pool_durations”设置为FALSE。这一参数为FALSE，将会使shared pool内存分配时，不再使某一类型的内存(比如perm)必须要求在一个固定的mini heap中。而实际上，sga_target设置为0之后，这一个参数自动会设为FALSE（由于这一参数是静态参数，所以修改了sga_target之后需要重启才会使这个隐含参数改变），所以建议的解决办法是设置sga_target参数，而不建议修改隐含参数。当然还有一种办法是完全让Oracle自动管理SGA，将buffer_cache_size和shared_pool_size等参数设置为0，但是正如前面所说，这种方法有比较大的缺陷。

---末了祝各位朋友五一节快乐。