诊断案例二-SGA设置过高导致的系统故障

案例描述:这是一个大型生产系统，问题出现时系统累计大量用户进程，用户请求得不到及时响应，新的进程不断尝试建立连接，连接数很快被用完。

最后系统处于挂起状态，无法进行服务响应。

数据库版本:9.2.0.3

操作系统:Solaris8

1.  登陆数据库，检查警告日志文件

接到问题报告之后，马上登陆数据库服务器，检查alert文件。

日志中记录如下错误信息，说明系统异步IO出现问题: 

WARNING: aiowait timed out 2 times
Tue Aug 26 15:33:32 2003
WARNING: aiowait timed out 2 times
Tue Aug 26 15:33:34 2003
WARNING: aiowait timed out 2 times
Tue Aug 26 15:33:36 2003
WARNING: aiowait timed out 2 times
Tue Aug 26 15:33:38 2003
WARNING: aiowait timed out 2 times
后来在其他平台上也发现类似的错误提示：
Tue Nov 11 14:08:24 2003
WARNING: aiowait timed out 1 times
Tue Nov 11 14:18:24 2003
WARNING: aiowait timed out 2 times
Tue Nov 11 14:28:24 2003
WARNING: aiowait timed out 3 times
Tue Nov 11 14:38:24 2003
WARNING: aiowait timed out 4 times
Tue Nov 11 14:38:24 2003
WARNING: aiowait timed out 5 times
Tue Nov 11 14:48:24 2003
WARNING: aiowait timed out 5 times
Tue Nov 11 14:58:24 2003
WARNING: aiowait timed out 6 times
Tue Nov 11 15:08:24 2003
WARNING: aiowait timed out 7 times
Tue Nov 11 15:08:24 2003
WARNING: aiowait timed out 7 times

注意到每次WARNING的间隔时间为10分钟。

注意：由于警报日志文件（alert_<sid>.log）中会记录数据库出现故障时的错误信息等，所以我们处理数据库问题时，通常应该首先检查该文件，看是否可以从中发现问题线索。

我们知道在SUN的某些版本上异步IO存在问题，而异步IO缺省是打开的 

SQL> show parameter disk_a
NAME          TYPE               VALUE
------------------------------------ ----------- ------------------------------
disk_asynch_io    Boolean             TRUE

针对此问题，我们暂时停用了数据库的异步IO写入。

2.  检查共享内存设置

alert文件中还记录了以下警告信息: 

  Tue Aug 26 21:37:40 2003
  WARNING: EINVAL creating segment of size 0x0000000190400000
  fix shm parameters in /etc/system or equivalent

该信息说明系统内核参数设置不合理或者和SGA不匹配，检查system配置文件： 

$ cat /etc/system
.......................
set shmsys:shminfo_shmmax=4096000000
set shmsys:shminfo_shmmin=1
set shmsys:shminfo_shmmni=200
set shmsys:shminfo_shmseg=200
set semsys:seminfo_semmap=1024
set semsys:seminfo_semmni=2048
set semsys:seminfo_semmns=2048
set semsys:seminfo_semmnu=2048
set semsys:seminfo_semume=200
set semsys:seminfo_semmsl=2048

发现最大共享内存段设置为4G

3.  检查SGA设置

察看内核参数之后，我们检查SGA设置： 

SQL> show sga
Total System Global Area   6695660272 bytes
Fixed Size                   740080 bytes
Variable Size             2399141888 bytes
Database Buffers          4294967296 bytes
Redo Buffers                 811008 bytes

发现SGA设置接近7G（超过了4G，Oracle将分配多个共享内存段），这也就是步骤2中警告提示出现的原因。

4.  交换区问题

我们用top工具检查系统运行状况 

# /usr/local/bin/top
 
last pid: 16899; load averages: 0.82, 0.81, 0.83 21:49:05
1230 processes:1228 sleeping, 1 running, 1 on cpu
CPU states: 50.1% idle, 7.4% user, 8.6% kernel, 33.9% iowait, 0.0% swap
Memory: 8192M real, 118M free, 12G swap in use, 11G swap free
 
PID USERNAME THR PRI NICE SIZE RES STATE TIME CPU COMMAND
15751 oracle 11 44 0 6456M 6408M sleep 0:02 0.49% oracle
15725 oracle 11 58 0 6458M 6410M sleep 0:02 0.46% oracle
251 root 12 48 0 7096K 1944K sleep 126:00 0.45% picld
16540 oracle 11 58 0 6458M 6411M sleep 0:01 0.45% oracle
16766 root 1 43 0 3744K 2248K cpu/1 0:01 0.41% top
16408 oracle 11 58 0 6457M 6410M sleep 0:01 0.34% oracle
15989 oracle 11 58 0 6458M 6409M sleep 0:01 0.34% oracle
15919 oracle 11 58 0 6457M 6409M sleep 0:02 0.30% oracle
16404 oracle 11 58 0 6457M 6409M sleep 0:00 0.28% oracle
16327 oracle 11 55 0 6457M 6410M sleep 0:00 0.27% oracle
14870 oracle 11 58 0 6457M 6412M sleep 0:05 0.24% oracle
16851 oracle 11 35 0 6457M 6411M sleep 0:00 0.22% oracle
16467 oracle 11 58 0 6457M 6409M sleep 0:00 0.21% oracle
16163 oracle 11 58 0 6457M 6408M sleep 0:03 0.21% oracle
15159 oracle 11 58 0 6457M 6408M sleep 0:05 0.21% oracle

发现在Top输出中，使用了12G的Swap，而物理内存几乎耗尽：

Memory: 8192M real, 118M free, 12G swap in use, 11G swap free

至此我们可以初步作出以下判断:

由于SGA设置过大(将近7G)导致运行时产生大量交换，大量SWAP交换进而引发磁盘I/O问题。这也就应该是我们第一步看到异步I/O错误的原因：

WARNING: aiowait timed out 1 times

大量交换导致数据库性能急剧下降，进而导致用户请求得不到快速响应，堵塞、累积，直至数据库失去响应。

5.  解决方案

此问题主要是由于SGA设置不当引起，我们马上缩小了SGA设置:

SQL> show sga
Total System Global Area 3591870848 bytes
Fixed Size                 735616 bytes
Variable Size           1442840576 bytes
Database Buffers        2147483648 bytes
Redo Buffers               811008 bytes

此时，数据库减少了交换,达到了稳定运行,用户请求可以得到快速响应。至此问题解决完成。 

6.  系统调整后状态

调整后系统运行状况如下TOP输出所示，内存使用已经降低到合理范围，系统得以稳定运行：

$ top
 
last pid: 12745;  load averages:  0.46,  0.79,  0.65           22:22:49
228 processes: 227 sleeping, 1 on cpu
CPU states: 92.3% idle,  5.0% user,  1.6% kernel,  1.1% iowait,  0.0% swap
Memory: 8192M real,  3817M free, 4015M swap in use, 15G swap free
 
PID USERNAME THR PRI NICE  SIZE   RES STATE    TIME    CPU COMMAND
 12610 oracle     1  51    0 3511M   22M sleep    0:04  1.96% oracle
 12595 oracle     1  48    0 3511M   22M sleep    0:03  0.92% oracle
 12630 oracle     1  38    0 3511M   21M sleep    0:01  0.84% oracle
 12614 oracle     1  46    0 3511M   22M sleep    0:01  0.64% oracle
 12620 oracle     1  58    0 3511M   22M sleep    0:01  0.53% oracle
 12709 oracle     1  48    0 3511M   21M sleep    0:00  0.45% oracle
   265 root      11  38    0 7032K 1920K sleep    3:16  0.42% picld
 12729 oracle     1   0    0 3511M   20M sleep    0:00  0.26% oracle
 12741 oracle     1  58    0 2768K 1760K cpu/3    0:00  0.19% top
 12745 oracle     1  44    0 3506M   16M sleep    0:00  0.17% oracle
 12711 oracle     1  48    0 3506M   16M sleep    0:00  0.11% oracle
 12738 oracle     1  43    0 3506M   16M sleep    0:00  0.06% oracle
  7606 oracle     1  45    0   17M 6928K sleep    0:07  0.05% tnslsnr
 12721 oracle     1  34    0 3506M   16M sleep    0:00  0.05% oracle
 12723 oracle     1  53    0 3506M   16M sleep    0:00  0.05% oracle

7.  一点总结

这个案例和前面我提到的另外一个极其相似，同样都是SGA设置不当引起的数据库问题。

这些问题本身并不复杂，应该在数据库规划和建设阶段就避免掉。良好的规划和设计是系统稳定运行的基础。如果在生产环境中遇到这类问题，更重要的是快速判断，准确定位，及时解决问题，减少故障对于业务系统的影响。

所以，在这些案例处理的过程中，最重要的其实只是一个思路和想法。

8.  后续研究

在故障处理之后，进一步研究发现，这一问题在Oracle9.2.0.3的Solaris平台上广泛存在，Oracle为此记录了Bug（Bug No：2086687）并做出了改进。

在Oracle9.2.0.3版本中，缺省的，Oracle在异步I/O出现问题时，会连续WARNING 100次，每次间隔10分钟，也就是在1000分钟之后会给出ORA-27083错误：

[oracle@jumper oracle]$ oerr ORA 27083
27083, 00000, "skgfrliopo: waiting for async I/Os failed"
// *Cause:  The aio_waitn() library call returned an error.
// *Action: Check errno.

这一设置让很多用户不满，因为连续100次的I/O超时可能已经给系统带来的严重的影响，所以在Oracle9.2.0.4版本中，Oracle引入了一个新的隐含参数用以控制在报告ORA-27083错误前WARNING的次数，这个参数是：_aiowait_timeouts，该参数的缺省值为100：

SQL> select * from v$version where rownum <2;
BANNER
----------------------------------------------------------------
Oracle9i Enterprise Edition Release 9.2.0.4.0 - Production
SQL> @GetParDescrb.sql
Enter value for par: aiowait
old   6:    AND x.ksppinm LIKE '%&par%'
new   6:    AND x.ksppinm LIKE '%aiowait%'
NAME               VALUE       DESCRIB
----------------- ------------ -------------------------------------------------------
_aiowait_timeouts       100    Number of aiowait timeouts before error is reported

到这里，这个问题可以告一段落了。