IO繁忙：WARNING:aiowait timed out 1 times

最新推荐文章于 2022-05-05 09:21:23 发布

iteye_4537

最新推荐文章于 2022-05-05 09:21:23 发布

阅读量245

点赞数

文章标签：数据库

系统IO繁忙，语句运行奇慢。
警告日志里面出现如下信息。

Tue Mar 17 21:12:27 2009
Completed checkpoint up to RBA [0x286c3.2.10], SCN: 8378443196795
Tue Mar 17 21:20:52 2009
WARNING: aiowait timed out 1 times
Tue Mar 17 21:23:01 2009
Completed checkpoint up to RBA [0x286c4.2.10], SCN: 8378443837692
Tue Mar 17 21:30:52 2009
WARNING: aiowait timed out 2 times
Tue Mar 17 21:40:52 2009
WARNING: aiowait timed out 3 times
Tue Mar 17 21:41:39 2009
Beginning log switch checkpoint up to RBA [0x286c5.2.10], SCN: 8378443843308
Thread 1 advanced to log sequence 165573
Current log# 2 seq# 165573 mem# 0: /oralogs01/CNSRPT/redo02a.log
Current log# 2 seq# 165573 mem# 1: /oralogs01_mirror/CNSRPT/redo02b.log
Tue Mar 17 21:50:21 2009
Completed checkpoint up to RBA [0x286c5.2.10], SCN: 8378443843308
Tue Mar 17 21:50:52 2009
WARNING: aiowait timed out 4 times
Tue Mar 17 22:00:52 2009
WARNING: aiowait timed out 5 times

**************************************************************************8

This is the Output of the TOP command

load averages: 1.07, 1.36, 1.49
23:08:09
155 processes: 153 sleeping, 2 on cpu
CPU states: 95.0% idle, 2.1% user, 2.9% kernel, 0.0% iowait, 0.0% swap
Memory: 20G real, 16G free, 2237M swap in use, 18G swap free

PID USERNAME THR PRI NICE SIZE RES STATE TIME CPU COMMAND
5085 oracle 1 60 2 31M 26M sleep 0:41 0.17% dtodump
17552 oracle 11 1 0 1131M 1115M sleep 5:04 0.17% oracle
7669 oracle 1 52 2 31M 26M sleep 0:20 0.13% dtodump
17647 oracle 11 1 0 1131M 1115M cpu15 4:52 0.12% oracle
17642 oracle 11 1 0 1131M 1114M sleep 4:56 0.06% oracle
17969 oracle 11 1 0 1131M 1115M sleep 4:37 0.05% oracle
17813 oracle 11 46 0 1131M 1114M sleep 5:04 0.05% oracle
17800 oracle 11 1 0 1131M 1115M sleep 4:51 0.05% oracle
17975 oracle 11 59 0 1131M 1114M sleep 5:18 0.04% oracle
17531 oracle 11 59 0 1131M 1115M sleep 5:23 0.04% oracle
17673 oracle 11 59 0 1131M 1114M sleep 5:28 0.03% oracle
17981 oracle 11 1 0 1131M 1115M sleep 5:04 0.03% oracle
2151 oracle 1 58 0 3992K 2264K cpu4 0:13 0.03% top
17817 oracle 11 1 0 1131M 1115M sleep 5:06 0.03% oracle
17601 oracle 11 1 0 1131M 1115M sleep 4:50 0.03% oracle
17822 oracle 11 1 0 1131M 1114M sleep 5:07 0.03% oracle
17651 oracle 11 1 0 1131M 1115M sleep 4:25 0.03% oracle
6913 oracle 1 59 2 1944K 1832K sleep 0:00 0.03% ora_mon_errchec
8632 oracle 1 60 2 1944K 1840K sleep 0:00 0.03% ora_adm_cdpagen
17731 oracle 11 59 0 1131M 1114M sleep 5:19 0.02% oracle
17966 oracle 11 10 1131M 1115M sleep 5:01 0.02% oracle
17654 oracle 11 1 0 1131M 1115M sleep 4:39 0.02% oracle
5469 oracle 1 60 2 31M 26M sleep 0:31 0.02% dtodump
17810 oracle 11 14 0 1131M 1114M sleep 5:24 0.02% oracle
17803 oracle 11 1 0 1131M 1114M sleep 4:45 0.02% oracle
17518 oracle 11 59 0 1131M 1114M sleep 4:42 0.02% oracle
17688 oracle 11 40 0 1131M 1115M sleep 4:33 0.02% oracle
4933 oracle 1 1 2 31M 26M sleep 0:38 0.02% dtodump
17777 oracle 11 57 0 1131M 1114M sleep 5:13 0.02% oracle
17977 oracle 11 1 0 1131M 1115M sleep 5:06 0.02% oracle
17973 oracle 11 11 0 1131M 1114M sleep 4:07 0.02% oracle
17971 oracle 11 530 1131M 1115M sleep 5:10 0.02% oracle
17844 oracle 11 1 0 1131M 1114M sleep 5:09 0.02% oracle
17949 oracle 11 49 0 1131M 1114M sleep 5:05 0.02% oracle
17858 oracle 11 59 0 1131M 1114M sleep 4:58 0.02% oracle
17931 oracle 11 1 0 1131M 1115M sleep 4:47 0.02% oracle
17754 oracle 11 1 0 1131M 1115M sleep 4:37 0.02% oracle
17807 oracle 11 1 0 1131M 1115M sleep 4:37 0.02% oracle
5105 oracle 1 53 2 5008K 3240K sleep 0:04 0.02% disk
7772 oracle 1 60 2 5008K 3248K sleep 0:02 0.02% disk
17983 oracle 11 1 0 1131M 1115M sleep 5:22 0.01% oracle
17704 oracle 11 1 0 1131M 1114M sleep 5:13 0.01% oracle
17578 oracle 11 59 0 1131M 1116M sleep 5:12 0.01% oracle
17879 oracle 11 1 0 1131M 1114M sleep 5:05 0.01% oracle
17979 oracle 11 1 0 1131M 1114M sleep 5:02 0.01% oracle
17620 oracle 11 49 0 1131M 1114M sleep 4:54 0.01% oracle
17904 oracle 11 1 0 1131M 1115M sleep 4:53 0.01% oracle
17819 oracle 11 1 0 1131M 1115M sleep 4:22 0.01% oracle
3584 oracle 1 39 2 31M 26M sleep 0:56 0.01% dtodump
18064 oracle 1 1 0 1129M 1094M sleep 14:20 0.01% oracle


Top 5 Timed Events                                         Avg %Total
~~~~~~~~~~~~~~~~~~                                        wait   Call
Event                                 Waits    Time (s)   (ms)   Time Wait
Class
------------------------------ ------------ ----------- ------ ------
----------
direct path read                 34,905,907   3,332,329     95   52.8   User
I/O
resmgr:cpu quantum                1,495,026     812,946    544   12.9
Scheduler
PX Deq Credit: send blkd           303,385     528,368   1742    8.4
Other
db file sequential read          17,095,772     519,679     30    8.2   User
I/O
db file scattered read            2,174,453     156,539     72    2.5   User
I/O
          -------------------------------------------------------------


                 extended device statistics                    tty    
device    r/s    w/s   kr/s   kw/s wait actv  svc_t  %w  %b  tin tout 
   2 2436 
md5       0.0    2.0    0.0   32.1  0.0  0.0   13.4   1   1 
md15      0.0    2.0    0.0   32.1  0.0  0.0    6.2   0   1 
md25      0.0    2.0    0.0   32.1  0.0  0.0    2.5   0   1 
md100   410.4   11.5 7504.8 1110.0  0.0 213.0  504.8   0 100 
md101     0.0    1.0    0.0    7.5  0.0  1.0  995.8   0 100 
md103     0.5    1.5    4.0   12.0  0.0  2.0  997.6   0 100 
md104     0.0    1.0    0.0    8.0  0.0  1.0  997.6   0 100 
md105     0.0    1.0    0.0    8.0  0.0  1.0  997.6   0 100 
md106   194.4    1.0 5183.6    8.0  0.0 167.9  859.1   0 100 
md107    40.1    0.0  914.1    0.0  0.0 39.1  975.7   0 100 
md108   175.4    1.0 1403.2 1026.3  0.0  1.0    5.5   0  96 
md109     0.0    2.5    0.0   20.0  0.0  0.0    3.2   0   1 
md110     0.0    2.5    0.0   20.0  0.0  0.0    2.5  0   1 
sd6       0.0    2.5    0.0   32.3  0.0  0.0    5.2   0   1 
sd30      0.0    2.5    0.0   32.3  0.0  0.0    8.3   0   2 
ssd5    175.4    6.0 1403.2 1066.4  0.0  1.0    5.4   0  95 
ssd15   235.0    5.5 6102.0   43.6 148.0 64.0  881.3 100 100 


nile002a# iostat -xtnz 2 5 | grep d100
  293.6  125.5 14531.8 2461.7  0.0 81.5    0.0  194.4   0  88 md/d100
  567.2   12.6 23324.7  100.7  0.0 713.3    0.0 1230.2   0 100 md/d100
  504.0    6.0 21213.8   44.3  0.0 718.6    0.0 1408.9   0 100 md/d100
  565.5    4.5 23539.9  540.0  0.0 772.4    0.0 1355.1   0 100 md/d100
  725.5    5.5 30165.6   40.5  0.0 733.9    0.0 1003.9   0 100 md/d100
nile002a-zone01.east:CNSRPT:/oradata04 $  df -h .
Filesystem             size   used  avail capacity  Mounted on
/oradata04     264G   248G     0K  100%    /oradata04

select bytes/1024/1024 from dba_data_files where file_name =
'/oradata04/CNSRPT/lg_data45.dbf';

BYTES/1024/1024
---------------
           4096

  select sum(bytes/1024/1024) from dba_free_space where file_id = 73;

SUM(BYTES/1024/1024)
--------------------
                3580
 alter database datafile '/oradata04/CNSRPT/lg_data45.dbf' resize 2048m;

Database altered.

 !df -h  /oradata04
Filesystem size   used  avail capacity  Mounted on
/oradata04             264G   246G     0K   100%    /oradata04
奇怪吧？
使用FSCK检查filesystem,发现问题，更换硬件解决。