database and os was hang with ORA-240 ERROR
Environment： AIX 6.1 ，TWO node rac，oracle 10.2.0.4
Symptom ：
用户反映无法打开MES程序，连接到2号节点查看，发现sqlplus /as sysdba
回车后卡死，cancel不掉？重新开一个连接，到root账户下 crsctl check crs 命令也卡死，lsnrctl status 命令卡死，OS命令正常。
1号节点正常。
Alterlog有如下报错
Sat Nov 3 16:37:32 2012
Thread 2 advanced to log sequence 55778 (LGWR switch)
Current log# 8 seq# 55778 mem# 0: +SFC3DB_DATA/sfc3db/onlinelog/group_8.304.722515055
Current log# 8 seq# 55778 mem# 1: +SFC3DB_ARCH/sfc3db/onlinelog/group_8.264.722515055
Sat Nov 3 16:40:19 2012
Errors in file /apps/oracle/admin/sfc3db/bdump/sfc3db2_arc0_1843352.trc:
ORA-00240: control file enqueue held for more than 120 seconds
Sat Nov 3 16:42:29 2012
Errors in file /apps/oracle/admin/sfc3db/bdump/sfc3db2_arc1_565424.trc:
ORA-00240: control file enqueue held for more than 120 seconds
Sat Nov 3 16:47:00 2012
kkjcre1p: unable to spawn jobq slave process
Sat Nov 3 16:47:00 2012
Sat Nov 3 17:04:22 2012
ksvsubmit: Process(O001) creation failed
系统应该是无法分配新的进程了，所以这些命令都卡死， 但是当时OS free的内存还有10多G，也远没有达到最大进程数。
我最后的解决办法是直接reboot OS，重启后OK， 各位大神有遇到过这种情况的吗？需要什么LOG 我发上来。
如下是trc文件
sfc3rac2:/apps/oracle/admin/sfc3db/bdump$ cat /apps/oracle/admin/sfc3db/bdump/sfc3db2_cjq0_5861420.trc
Dump file /apps/oracle/admin/sfc3db/bdump/sfc3db2_cjq0_5861420.trc
Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bit Production
With the Partitioning, Real Application Clusters, OLAP, Data Mining
and Real Application Testing options
ORACLE_HOME = /apps/oracle/product/10.2.0
System name: AIX
Node name: sfc3rac2
Release: 1
Version: 6
Machine: 00C8B9724C00
Instance name: sfc3db2
Redo thread mounted by this instance: 2
Oracle process number: 15
Unix process pid: 5861420, image: oracle@sfc3rac2 (CJQ0)
*** 2012-11-03 06:00:41.427
*** SERVICE NAMESYS$BACKGROUND) 2012-11-03 06:00:41.419
*** SESSION ID2192.1) 2012-11-03 06:00:41.419
GATHER_STATS_JOB: Stopped by Scheduler.
Consider increasing the maintenance window duration if this happens frequently.
The following objects/segments were not analyzed due to timeout:
*** 2012-11-03 16:31:39.479
Waited for process J000 to initialize for 60 seconds
*** 2012-11-03 16:31:39.479
Dumping diagnostic information for J000:
OS pid = 917522
loadavg : 3.77 3.49 3.60
swap info: free_mem = 9427.14M rsv = 64.00M
alloc = 241.15M avail = 16384.00M swap_free = 16142.85M
F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
1040005 A oracle 917522 1 0 60 20 1ad230590 89196 16:30:38 - 0:00 [oracle]
skgpgpstack: read() for cmd /bin/sh -c '/usr/bin/procstack 917522 2>&1' timed out after 60 seconds
*** 2012-11-03 16:33:40.701
*** 2012-11-03 16:33:50.907
Waited for process J000 to initialize for 70 seconds
*** 2012-11-03 16:33:50.907
Dumping diagnostic information for J000:
OS pid = 917522
loadavg : 2.86 3.25 3.49
swap info: free_mem = 9348.35M rsv = 64.00M
alloc = 241.11M avail = 16384.00M swap_free = 16142.89M
F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
1040005 A oracle 917522 1 0 60 20 1ad230590 89196 16:30:38 - 0:00 [oracle]
skgpgpstack: read() for cmd /bin/sh -c '/usr/bin/procstack 917522 2>&1' timed out after 60 seconds
*** 2012-11-03 16:35:52.258
*** 2012-11-03 16:36:02.459
Waited for process J000 to initialize for 80 seconds
*** 2012-11-03 16:36:02.459
Dumping diagnostic information for J000:
OS pid = 917522
loadavg : 2.74 3.00 3.36
swap info: free_mem = 9385.39M rsv = 64.00M
alloc = 241.10M avail = 16384.00M swap_free = 16142.90M
F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
1040005 A oracle 917522 1 0 60 20 1ad230590 89196 16:30:38 - 0:00 [oracle]
skgpgpstack: read() for cmd /bin/sh -c '/usr/bin/procstack 917522 2>&1' timed out after 60 seconds
*** 2012-11-03 16:38:03.960
*** 2012-11-03 16:38:14.165
Waited for process J000 to initialize for 90 seconds
*** 2012-11-03 16:38:14.165
Dumping diagnostic information for J000:
OS pid = 917522
loadavg : 2.56 2.96 3.30
swap info: free_mem = 9440.27M rsv = 64.00M
alloc = 241.00M avail = 16384.00M swap_free = 16143.00M
F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
1040005 A oracle 917522 1 0 60 20 1ad230590 89196 16:30:38 - 0:00 [oracle]
skgpgpstack: read() for cmd /bin/sh -c '/usr/bin/procstack 917522 2>&1' timed out after 60 seconds
*** 2012-11-03 16:40:16.175
*** 2012-11-03 16:40:26.384
Waited for process J000 to initialize for 100 seconds
*** 2012-11-03 16:40:26.384
Dumping diagnostic information for J000:
OS pid = 917522
loadavg : 2.82 2.90 3.23
swap info: free_mem = 9488.88M rsv = 64.00M
alloc = 240.96M avail = 16384.00M swap_free = 16143.04M
F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
1040005 A oracle 917522 1 0 60 20 1ad230590 89196 16:30:38 - 0:00 [oracle]
skgpgpstack: read() for cmd /bin/sh -c '/usr/bin/procstack 917522 2>&1' timed out after 60 seconds
*** 2012-11-03 16:42:29.100
*** 2012-11-03 16:42:39.305
Waited for process J000 to initialize for 110 seconds
*** 2012-11-03 16:42:39.305
Dumping diagnostic information for J000:
OS pid = 917522
loadavg : 4.05 3.26 3.32
swap info: free_mem = 9640.50M rsv = 64.00M
alloc = 240.90M avail = 16384.00M swap_free = 16143.10M
F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
1040005 A oracle 917522 1 0 60 20 1ad230590 89196 16:30:38 - 0:00 [oracle]
skgpgpstack: read() for cmd /bin/sh -c '/usr/bin/procstack 917522 2>&1' timed out after 60 seconds
*** 2012-11-03 16:44:43.732
*** 2012-11-03 16:44:53.936
Waited for process J000 to initialize for 120 seconds
*** 2012-11-03 16:44:53.936
Dumping diagnostic information for J000:
OS pid = 917522
loadavg : 3.03 3.16 3.28
swap info: free_mem = 9667.09M rsv = 64.00M
alloc = 240.84M avail = 16384.00M swap_free = 16143.16M
F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
1040005 A oracle 917522 1 0 60 20 1ad230590 89196 16:30:38 - 0:00 [oracle]
skgpgpstack: read() for cmd /bin/sh -c '/usr/bin/procstack 917522 2>&1' timed out after 60 seconds
*** 2012-11-03 16:47:00.265
Killing process (ospid 917522): (reason=x4 error=0)
... and the process is still alive after kill!
*** 2012-11-03 17:05:23.892
Waited for process J000 to initialize for 60 seconds
*** 2012-11-03 17:05:23.892
Dumping diagnostic information for J000:
OS pid = 3915970
loadavg : 2.43 2.42 2.75
swap info: free_mem = 10365.04M rsv = 64.00M
alloc = 239.53M avail = 16384.00M swap_free = 16144.47M
F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
1040005 A oracle 3915970 1 0 60 20 105d26590 89196 17:04:22 - 0:00 [oracle]
skgpgpstack: read() for cmd /bin/sh -c '/usr/bin/procstack 3915970 2>&1' timed out after 60 seconds
*** 2012-11-03 17:07:35.954
*** 2012-11-03 17:07:46.156
Waited for process J000 to initialize for 70 seconds
*** 2012-11-03 17:07:46.156
Dumping diagnostic information for J000:
OS pid = 3915970
loadavg : 2.24 2.33 2.67
swap info: free_mem = 10400.53M rsv = 64.00M
alloc = 239.37M avail = 16384.00M swap_free = 16144.63M
F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
1040005 A oracle 3915970 1 0 60 20 105d26590 89196 17:04:22 - 0:00 [oracle]
skgpgpstack: read() for cmd /bin/sh -c '/usr/bin/procstack 3915970 2>&1' timed out after 60 seconds
*** 2012-11-03 17:09:58.294
*** 2012-11-03 17:10:08.495
Waited for process J000 to initialize for 80 seconds
*** 2012-11-03 17:10:08.495
Dumping diagnostic information for J000:
OS pid = 3915970
loadavg : 2.36 2.38 2.64
swap info: free_mem = 10389.09M rsv = 64.00M
alloc = 239.23M avail = 16384.00M swap_free = 16144.77M
F S UID PID PPID C PRI NI ADDR SZ WCHAN STIME TTY TIME CMD
1040005 A oracle 3915970 1 0 60 20 105d26590 89196 17:04:22 - 0:00 [oracle]
skgpgpstack: read() for cmd /bin/sh -c '/usr/bin/procstack 3915970 2>&1' timed out after 60 seconds
*** 2012-11-03 17:12:20.685
*** 2012-11-03 17:12:30.886
Waited for process J000 to initialize for 90 seconds
*** 2012-11-03 17:12:30.886
Dumping diagnostic information for J000:
还有个trc文件太大暂时不放了 。
[解决办法]
看他给的原因好像是锁问题。
thank you
标志了以后用
[解决办法]
http://www.xifenfei.com/1838.html
LZ看看这个，操作系统bug导致ASM出现问题而引起的。
