Last updated on JUNE 29, 2016
Applies to:
Oracle Database - Enterprise Edition - Version 11.2.0.4 and laterIBM: Linux on System z
Symptoms
11g Database and ASM hang,
and both DB & ASM Alert logs start getting "WARNING:io_getevents timed out 600 sec" for next 11 hours,
and several hours later, DB Alert gets error "ORA-00020: maximum number of processes (150) exceeded".
Database was non-responsive and ASM was also not responding during 11 hour hang.
There is one "timed out" device error in "/var/log/messages" for device "dasdbt" during 11 hour hang:
Jul 13 22:01:36 xxx kernel: dasd-eckd.157e58: 0.0.0657: cqr 00000000024cfd18 timed out (30s), 255 retries remaining
OSWatcher data was captured during the 11 hour hang period and all the OSWatcher iostat files
showed timed-out device "dasdbt" was the only device running with util = 100% or total "device saturation" for 11+ hours.
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util
dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 16.00 0.00 0.00 100.00
%util
Percentage of CPU time during which I/O requests were issued to the device (bandwidth utilization for the device).
Device saturation occurs when this value is close to 100%.
Search "dasdbt" (58 hits in 1 file)
osw\oswiostat\xxx_iostat_15.07.13.2200.dat (58 hits)
Line 76: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 2.44 0.00 0.00 122.00
zzz ***Mon Jul 13 22:02:09 EDT 2015
Line 168: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 2.00 0.00 0.00 100.00
Line 260: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 4.00 0.00 0.00 100.00
Line 352: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 4.68 0.00 0.00 117.00
===
Line 5136: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 6.00 0.00 0.00 100.00
Line 5228: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 6.00 0.00 0.00 100.00
Line 5320: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 5.94 0.00 0.00 99.00
zzz ***Mon Jul 13 22:59:30 EDT 2015
Search "dasdbt" (32 hits in 1 file)
osw\oswiostat\xxx_iostat_15.07.14.0900.dat (32 hits)
Line 76: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 16.16 0.00 0.00 101.00
zzz ***Tue Jul 14 09:00:26 EDT 2015
Line 168: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 15.84 0.00 0.00 99.00
Line 260: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 16.16 0.00 0.00 101.00
Line 352: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 16.16 0.00 0.00 101.00
===
Line 2560: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 15.84 0.00 0.00 99.00
Line 2652: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 16.00 0.00 0.00 100.00
Line 2744: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 16.00 0.00 0.00 100.00
Line 2836: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 16.00 0.00 0.00 100.00
Line 2928: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 16.00 0.00 0.00 100.00
zzz ***Tue Jul 14 09:32:01 EDT 2015
Result from "lsdasd" command:
Device "dasdbt" ( dasd-eckd.157e58: 0.0.0657 )
dasd-eckd.157e58: 0.0.0657:
0.0.0657 active dasdbt 94:284 ECKD 4096 23033MB 5896620
RDA > ASM > Device List
lrwxrwxrwx 1 root root [0x0] Jul 14 13:59 2015 Jul 14 13:59 2015 ASM0657 -> dasdbt1
Disk Partition Information
From /proc/partitions
major minor #blocks name
===
94 284 23586480 dasdbt
94 285 23586384 dasdbt1
Listing of Devices from /dev
===
brw-rw---- 1 root disk [0x105e1c] Jul 14 13:59 2015 Jul 14 13:59 2015 dasdbt
brw-rw---- 1 grid asmadmin [0x105e1d] Jul 17 12:22 2015 Jul 17 12:22 2015 dasdbt1
/dev/.udev/links/ASM0657:
drwxr-xr-x 2 root root 60 Jul 14 13:59 2015 Jul 14 13:59 2015 .
drwxr-xr-x 702 root root 14040 Jul 14 14:00 2015 Jul 14 14:00 2015 ..
lrwxrwxrwx 1 root root 52 Jul 14 13:59 2015 Jul 14 13:59 2015 b94:285 -> /devices/css0/0.0.004d/0.0.0657/block/dasdbt/dasdbt1
/dev/.udev/links/disk\x2fby-id\x2fccw-0X0657:
drwxr-xr-x 2 root root 60 Jul 14 13:59 2015 Jul 14 13:59 2015 .
drwxr-xr-x 702 root root 14040 Jul 14 14:00 2015 Jul 14 14:00 2015 ..
lrwxrwxrwx 1 root root 44 Jul 14 13:59 2015 Jul 14 13:59 2015 b94:284 -> /devices/css0/0.0.004d/0.0.0657/block/dasdbt
/dev/.udev/links/disk\x2fby-id\x2fccw-0X0657-part1:
drwxr-xr-x 2 root root 60 Jul 14 13:59 2015 Jul 14 13:59 2015 .
drwxr-xr-x 702 root root 14040 Jul 14 14:00 2015 Jul 14 14:00 2015 ..
lrwxrwxrwx 1 root root 52 Jul 14 13:59 2015 Jul 14 13:59 2015 b94:285 -> /devices/css0/0.0.004d/0.0.0657/block/dasdbt/dasdbt1
Jul 13 22:01:36 xxx kernel: dasd-eckd.157e58: 0.0.0657: cqr 00000000024cfd18 timed out (30s), 255 retries remaining
OSWatcher data was captured during the 11 hour hang period and all the OSWatcher iostat files
showed timed-out device "dasdbt" was the only device running with util = 100% or total "device saturation" for 11+ hours.
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await svctm %util
dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 16.00 0.00 0.00 100.00
%util
Percentage of CPU time during which I/O requests were issued to the device (bandwidth utilization for the device).
Device saturation occurs when this value is close to 100%.
Search "dasdbt" (58 hits in 1 file)
osw\oswiostat\xxx_iostat_15.07.13.2200.dat (58 hits)
Line 76: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 2.44 0.00 0.00 122.00
zzz ***Mon Jul 13 22:02:09 EDT 2015
Line 168: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 2.00 0.00 0.00 100.00
Line 260: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 4.00 0.00 0.00 100.00
Line 352: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 4.68 0.00 0.00 117.00
===
Line 5136: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 6.00 0.00 0.00 100.00
Line 5228: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 6.00 0.00 0.00 100.00
Line 5320: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 5.94 0.00 0.00 99.00
zzz ***Mon Jul 13 22:59:30 EDT 2015
Search "dasdbt" (32 hits in 1 file)
osw\oswiostat\xxx_iostat_15.07.14.0900.dat (32 hits)
Line 76: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 16.16 0.00 0.00 101.00
zzz ***Tue Jul 14 09:00:26 EDT 2015
Line 168: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 15.84 0.00 0.00 99.00
Line 260: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 16.16 0.00 0.00 101.00
Line 352: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 16.16 0.00 0.00 101.00
===
Line 2560: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 15.84 0.00 0.00 99.00
Line 2652: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 16.00 0.00 0.00 100.00
Line 2744: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 16.00 0.00 0.00 100.00
Line 2836: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 16.00 0.00 0.00 100.00
Line 2928: dasdbt 0.00 0.00 0.00 0.00 0.00 0.00 0.00 16.00 0.00 0.00 100.00
zzz ***Tue Jul 14 09:32:01 EDT 2015
Result from "lsdasd" command:
Device "dasdbt" ( dasd-eckd.157e58: 0.0.0657 )
dasd-eckd.157e58: 0.0.0657:
0.0.0657 active dasdbt 94:284 ECKD 4096 23033MB 5896620
RDA > ASM > Device List
lrwxrwxrwx 1 root root [0x0] Jul 14 13:59 2015 Jul 14 13:59 2015 ASM0657 -> dasdbt1
Disk Partition Information
From /proc/partitions
major minor #blocks name
===
94 284 23586480 dasdbt
94 285 23586384 dasdbt1
Listing of Devices from /dev
===
brw-rw---- 1 root disk [0x105e1c] Jul 14 13:59 2015 Jul 14 13:59 2015 dasdbt
brw-rw---- 1 grid asmadmin [0x105e1d] Jul 17 12:22 2015 Jul 17 12:22 2015 dasdbt1
/dev/.udev/links/ASM0657:
drwxr-xr-x 2 root root 60 Jul 14 13:59 2015 Jul 14 13:59 2015 .
drwxr-xr-x 702 root root 14040 Jul 14 14:00 2015 Jul 14 14:00 2015 ..
lrwxrwxrwx 1 root root 52 Jul 14 13:59 2015 Jul 14 13:59 2015 b94:285 -> /devices/css0/0.0.004d/0.0.0657/block/dasdbt/dasdbt1
/dev/.udev/links/disk\x2fby-id\x2fccw-0X0657:
drwxr-xr-x 2 root root 60 Jul 14 13:59 2015 Jul 14 13:59 2015 .
drwxr-xr-x 702 root root 14040 Jul 14 14:00 2015 Jul 14 14:00 2015 ..
lrwxrwxrwx 1 root root 44 Jul 14 13:59 2015 Jul 14 13:59 2015 b94:284 -> /devices/css0/0.0.004d/0.0.0657/block/dasdbt
/dev/.udev/links/disk\x2fby-id\x2fccw-0X0657-part1:
drwxr-xr-x 2 root root 60 Jul 14 13:59 2015 Jul 14 13:59 2015 .
drwxr-xr-x 702 root root 14040 Jul 14 14:00 2015 Jul 14 14:00 2015 ..
lrwxrwxrwx 1 root root 52 Jul 14 13:59 2015 Jul 14 13:59 2015 b94:285 -> /devices/css0/0.0.004d/0.0.0657/block/dasdbt/dasdbt1
Cause
Sign In with your My Oracle Support account |
|
Don't have a My Oracle Support account? Click to get started |
My Oracle Support provides customers with access to over a
Million Knowledge Articles and hundreds of Community platforms