IO繁忙:WARNING:aiowait timed out 1 times

来源:互联网 发布:淘宝售后服务图片 编辑:程序博客网 时间:2024/05/17 08:44

系统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,发现问题,更换硬件解决。

 

原创粉丝点击