故障现象

2004年6月8日上午10:00,内蒙古巴盟网通用户反映在OSS系统界面“话单查询”里查询单个用户五天的话单特别慢，查询很长时间无结果。

例如：在OSS系统界面“综合查询”内点击“收费”-〉“话单查询”，键入“用户号码，起始时间：2004-01-01 00：00：00，结束时间：2004-06-01 23：00：00”，点击查询后，IE进度条缓慢，很长时间不返回结果。

故障分析

经过分析，此现象和数据库的性能有关，主要是数据库初始化参数调整不合理造成的性能低下。具体分析步骤如下：

• 首先查询话单表的索引是否失效，因为失效的索引会带来差的SQL查询效率。

SQL>select INDEX_NAME,status from USER_IND_PARTITIONS where status!='USABLE';

no rows selected.

结果说明没有失效的话单表索引。

• 用top命令看到可用物理内存很低，只剩下100M，有大量的SWAP区内存正在使用，ORACLE单个会话占用的内存很多，经查看ORACLE初始化参数shared_pool_size的值设置的过高，应重新调整。

top的结果:

last pid:4565;load averages:0.15,0.20,0.20
10:09:56

170 processes: 169 sleeping, 1 on cpu

CPU states: 84.9% idle,1.6% user,1.1% kernel, 12.4% iowait,0.0% swap

Memory: 4096M real, 100M free, 1343M swap in use, 6851M swap free

PID USERNAME THR PRI NICESIZERES STATETIMECPU COMMAND

10459 oracle1590 1978M 1953M sleep0:530.79% oracle

2258 oracle1100 1976M 1951M sleep 116:570.65% oracle

25639 oracle1580 1975M 1949M sleep1:560.27% oracle

1948 oracle1580 1976M 1948M sleep3:340.18% oracle

4002 wacos6474 9616K 2344K sleep27:260.18% cdr_backup

2271 oracle1590 1975M 1947M sleep15:130.16% oracle

1958 oracle1480 1976M 1949M sleep2:260.13% oracle

1928 oracle1580 1976M 1951M sleep4:280.12% oracle

1926 oracle1580 1976M 1949M sleep2:060.12% oracle

1956 oracle 1580 1976M 1949M sleep2:230.11% oracle

1952 oracle1590 1976M 1949M sleep2:190.10% oracle

403 root10210 4896K 4608K sleep16:320.09% picld

1954 oracle1480 1976M 1949M sleep2:040.08% oracle

2189 oracle1580 1976M 1949M sleep15:510.08% oracle

• 为了进一步分析ORACLE的性能，用ORACLE自带的诊断工具statspack做性能快照分析，统计时段为1小时，时间从下午17：00-18：00之间。这段时间业务比较繁忙，选择在此时段内对整个系统进行性能分析，能够得到更加准确的信息。

安装statspack性能分析工具:

SQL>connect internal

SQL>alter system set timed_statistics=true;(收集操作系统的计时信息)

SQL>@?/rdbms/admin/spcreate.sql

SQL>execute statspack.snap(17:00的时候运行一次)

SQL>execute statspack.snap(18:00的时候运行一次)

SQL>@?/rdbms/admin/spreport(产生性能分析报告)

截取报告的部分内容如下:

STATSPACK report for

DB NameDB IdInstanceInst Num ReleaseOPS Host

------------ ----------- ------------ -------- ----------- --- ------------

ORCL1000277484 ORCL1 8.1.7.3.0NObm_db1

Snap IdSnap TimeSessions

------- ------------------ --------

Begin Snap:1 08-Jun-04 17:00:15116

End Snap:2 08-Jun-04 18:00:40116

Elapsed:60.42 (mins)

Cache Sizes

~~~~~~~~~~~

db_block_buffers:180000log_buffer:8192000

db_block_size:8192shared_pool_size: 314572800

Load Profile

~~~~~~~~~~~~Per SecondPer Transaction

------------------------------

Redo size:11,005.012,280.39

Logical reads:65,704.2113,614.83

Block changes:67.9614.08

Physical reads:1,392.89288.63

Physical writes:11.612.40

User calls:172.6335.77

Parses:29.116.03

Hard parses:0.010.00

Sorts:7.811.62

Logons:0.140.03

Executes:101.4421.02

Transactions:4.83

% Blocks changed per Read:0.10Recursive Call %:41.29

Rollback per transaction %:0.28Rows per Sort:25.55

Instance Efficiency Percentages (Target 100%)

~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

Buffer Nowait %:100.00Redo NoWait %:100.00

BufferHit%:97.88In-memory Sort %:100.00

Library Hit%:99.98Soft Parse %:99.96

Execute to Parse %:71.30Latch Hit %:99.99

Parse CPU to Parse Elapsd %:62.24% Non-Parse CPU:99.99

Shared Pool StatisticsBeginEnd

------------

Memory Usage %:24.1524.44

% SQL with executions>1:75.0476.95

% Memory for SQL w/exec>1:75.4979.90

Top 5 Wait Events

~~~~~~~~~~~~~~~~~Wait% Total

EventWaitsTime (cs)Wt Time

-------------------------------------------- ------------ ------------ -------

db file sequential read5,030,075389,07186.37

log file sync17,47021,1874.70

log file parallel write17,64018,6114.13

db file parallel write1,85314,9303.31

db file scattered read3,1492,297.51

对报告分析后发现有一些不合理的初始化参数需要调整，建议如下调整：

• 报告中发现全表扫描的语句特别多，因此建议程序中尽量避免使用全表扫描，减少IO等待，从而加快语句的执行速度。

类似如下语句需要优化：

SQL>select count(*) as totalcount from LOCALUSAGE where serviceid=:"SYS_B_0" and starttime>=to_date(:"SYS_B_1",:"SYS_B_2") and starttime <=to_date(:"SYS_B_3",:"SYS_B_4") and ( LOCALROAMINGCHARGE >:"SYS_B_5"or LocalCharge >:"SYS_B_6"or UrbanCharge >:"SYS_B_7" or ruralcharge >:"SYS_B_8")；

• 调整db_file_multiblock_read_count=16

这个参数指定一个完全连续扫描的一次I/O操作过程中读取的块的最大数量。它的增加对IO是有改善的，特别是在做full table scan的时候，可以减少IO的次数。

•  调整db_block_lru_latches=2

这个参数指定LRU 闩锁集数量的上限。LRU锁的数量是在Oracle数据库内部用来管理数据库缓冲的，它严重依赖于服务器上CPU的数量,这个值通常设置为服务器上cpu_count的一半，增大这个值有利于提高磁盘的I/O性能。

•  调整session_cached_cursors=200

这个参数指定要高速缓存的会话游标的数量，对同一SQL语句进行多次语法分析后，它的会话游标将被移到该会话的游标高速缓存中。增大这个值可以缩短语法分析的时间，因为游标被高速缓存，无需被重新打开。

•  调整log_buffer=1048576

参数log_buffer指定在 LGWR 将重做日志缓冲区里的内容写入重做日志文件之前，用于缓存这些条目的内存量。这个参数以字节为单位，同时受cpu_count的影响, log_buffer如果被设置得太高（例如，大于1MB），这会引起性能问题，因为大容量的结果会使得写入同步进行（例如，日志同步等待事件非常高）。

•  调整db_block_buffers = 200000shared_pool_size= 262144000

按照杭州的规划，Oracle最终运行起来占用近1/2的物理内存。其中最主要的两个参数为：

db_block_buffers：它的配置原则是，最终数据块缓存占据1/3的内存。

Shared_pool_size：它的配置原则是，基本控制在200-500M左右。

•  从报告中发现系统等待最严重的五个事件为:db file sequential read，log file sync，log file parallel write，db file parallel write和db file scattered read.
  • 对于db file sequential read等待事件，一般问题出现在读索引上，建议将wacos表空间和wacos索引表空间分开存储在不同的物理卷下，以提高磁盘的I/O性能。
  • 对于db file scattered read等待事件，建议程序中尽量避免使用全表扫描的语句，或者可以增大db_file_multiblock_read_count的值，提高全表扫描一次读取数据块的速度，减少磁盘I/O。
  • 对于db file parallel write等待事件，说明DBWR进程正等待把缓冲区的内容并行写入数据文件中去,等待将一直持续到所有的I/O全部完成。建议增大初始化参数中的db_writer_processes的值，可以增大到4。
  • 对于log file sync等待事件，说明任何时候一个事物提交时，它将通知LGWR将LOG_BUFFER写入日志文件，如果此部分占用时间较长，应减少COMMIT的次数，建议将重做日志放到较快的磁盘上进行存储。
  • 对于log file parallel write等待事件，和上面一样建议将重做日志放到较快的磁盘上进行存储。

故障处理

调整initORCL.ora里不合理的参数，具体调整为：

process=200

log_buffer=1048576

session_cached_cursors=200

db_block_lru_latches=2

shared_pool_size= 262144000

db_block_buffers = 200000

sort_area_size = 6553600

sort_area_retained_size = 6553600

db_file_multiblock_read_count = 16

处理结果

调整完重启DB后，发现查询一切正常，很快就返回了结果。

总结

数据库里初始化参数设置不合理, 内存富余太少, 导致数据库运行使用大量的swap空间，数据库性能很差，导致通过OSS界面查询话单很慢。这时需要通过调整数据库初始化参数解决该问题。从性能方面考虑，数据库服务器最好能富余300－500M以上的内存。