数据库：Oracle 10.2.0.1 平台：HP-UX B.11.23 ia64 故障描述客户反映在2009-01-19上午7点左右，应用无法连接到数据库，之后将数据库重启，并增大了PROCESSES参数。客户希望查找问题原因。 原因分析： 从ALERT LOG中的信息可以看到： Tue Jan 19 06:11:22 2010 Process J000 died, see its trace file Tue Jan 19 06:11:22 2010 kkjcre1p: unable to spawn jobq slave process Tue Jan 19 06:11:22 2010 Errors in file /oracle/admin/vc/bdump/vc_cjq0_16001.trc: Tue Jan 19 06:12:33 2010 Process J000 died, see its trace file Tue Jan 19 06:12:33 2010 kkjcre1p: unable to spawn jobq slave process Tue Jan 19 06:12:33 2010 Errors in file /oracle/admin/vc/bdump/vc_cjq0_16001.trc: 在19号的06:11:22时出现错误： 原因是由于无法分配jobq slave process进程导致J000进程died。 从/oracle/admin/vc/bdump/vc_cjq0_16001.trc看到： *** 2010-01-19 06:11:22.293 Process J000 is dead (pid=15748, state=3): *** 2010-01-19 06:12:33.315 Process J000 is dead (pid=15947, state=3): 该问题出现过两次，都是由调度进程CJQ0产生的。 从同时间点的后台trace文件看到出现该问题的主要原因是达到了最大进程数限制 /oracle/admin/vc/bdump/vc_ora_15748.trc内容： error 20 in job queue process ORA-00020: maximum number of processes (1000) exceeded 尽管无法分配进程给job队列使用，但是并不会导致数据库宕机或挂起。数据库仅是由于达到了最大进程数限制，而导致应用无法连接。 此时数据库的状态仍然是OPEN状态，仍能通过管理员用户登入到数据库。 客户在数据库出现问题之后对数据库的操作： 06:53:41开始，使用管理员用户重启数据库实例： Tue Jan 19 06:53:41 2010 Starting ORACLE instance (normal) 第一次启动不成功，于07:12:36将数据库shutdown abort： Tue Jan 19 07:12:36 2010 Shutting down instance (abort) License high water mark = 980 Instance terminated by USER, pid = 25808 之后在07:12:46时正常重启数据库，并启动成功： Tue Jan 19 07:12:46 2010 Starting ORACLE instance (normal) 分析listener.log：分析大量连接的客户端： 通过统计分析listener.log日志，2.log为最后100000行的listener.log，统计结果如下： 统计2010年1月19日，1-7点之间的192.168.1.6的连接信息： cat 2.log | grep "19-JAN-2010 01" | grep "establish" | grep "192.168.1.6" | wc -l result:217 cat 2.log | grep "19-JAN-2010 02" | grep "establish" | grep "192.168.1.6" | wc -l result:283 cat 2.log | grep "19-JAN-2010 03" | grep "establish" | grep "192.168.1.6" | wc -l result:275 cat 2.log | grep "19-JAN-2010 04" | grep "establish" | grep "192.168.1.6" | wc -l result:282 cat 2.log | grep "19-JAN-2010 05" | gre |
p "establish" | grep "192.168.1.6" | wc -l result:290
cat 2.log | grep "19-JAN-2010 06" | grep "establish" | grep "192.168.1.6" | wc -l result:397
统计2010年1月19日，1-7点之间的132.96.63.75的连接信息：
cat 2.log | grep "19-JAN-2010 01" | grep "establish" | grep "132.96.63.75" | wc -l result:132
cat 2.log | grep "19-JAN-2010 02" | grep "establish" | grep "132.96.63.75" | wc -l result:132
cat 2.log | grep "19-JAN-2010 03" | grep "establish" | grep "132.96.63.75" | wc -l result:132
cat 2.log | grep "19-JAN-2010 04" | grep "establish" | grep "132.96.63.75" | wc -l result:132
cat 2.log | grep "19-JAN-2010 05" | grep "establish" | grep "132.96.63.75" | wc -l result:132
cat 2.log | grep "19-JAN-2010 06" | grep "establish" | grep "132.96.63.75" | wc -l result:85
统计2010年1月18日，1-7点之间的192.168.1.6的连接信息：
cat 2.log | grep "18-JAN-2010 01" | grep "establish" | grep "192.168.1.6" | wc -l result:68
cat 2.log | grep "18-JAN-2010 02" | grep "establish" | grep "192.168.1.6" | wc -l result:20
cat 2.log | grep "18-JAN-2010 03" | grep "establish" | grep "192.168.1.6" | wc -l result:26
cat 2.log | grep "18-JAN-2010 04" | grep "establish" | grep "192.168.1.6" | wc -l result:21
cat 2.log | grep "18-JAN-2010 05" | grep "establish" | grep "192.168.1.6" | wc -l result:69
cat 2.log | grep "18-JAN-2010 06" | grep "establish" | grep "192.168.1.6" | wc -l result:20
统计2010年1月18日，1-7点之间的132.96.63.75的连接信息： ;
cat 2.log | grep "18-JAN-2010 01" | grep "establish" | grep "132.96.63.75" | wc -l result:132
cat 2.log | grep "18-JAN-2010 02" | grep "establish" | grep "132.96.63.75" | wc -l result:132
cat 2.log | grep "18-JAN-2010 03" | grep "establish" | grep "132.96.63.75" | wc -l result:132
cat 2.log | grep "18-JAN-2010 04" | grep "establish" | grep "132.96.63.75" | wc -l result:132
cat 2.log | grep "18-JAN-2010 05" | grep "establish" | grep "132.96.63.75" | wc -l result:132
cat 2.log | grep "18-JAN-2010 06" | grep "establish" | grep "132.96.63.75" | wc -l result:132
由统计可见192.168.1.6出现了比平时更多的连接。
Listener.log报错信息：
19-JAN-2010 06:07:33 * (CONNECT_DATA=(SID=vc)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=oracle))) * (ADDRESS=(PROTOCOL=tcp)(HOST=192.168.1.
6)(PORT=62396)) * establish * vc * 12518
TNS-12518: TNS:listener could not hand off client connection
TNS-12547: TNS:lost contact
TNS-12560: TNS:protocol adapter error
TNS-00517: Lost contact
HPUX Error: 32: Broken pipe
2010-01-19第一次出现连接失败的时间为06:07:33，客户端为192.168.1.6，该时间点与数据库的alert log报错的时间点极为接近。
TNS-12518: TNS:listener could not hand off client connection
该错误通常表明是由于资源问题导致的连接失败。
AWR报告分析：19号5点-6点AWR报告/tmp/awrrpt_1_15639_15640.html中同样也出现了关于资源限制的警告信息。
Resource Limit Stats
only rows with Current or Maximum Utilization > 80% of Limit are shown
ordered by resource name
Current Maximum Initial
Resource Name Utilization Utilization Allocation Limit
------------- ------------- ------------ ----------- ------
processes 991 999 1000 1000
sessions&n bsp; 997 1,003 1105 1105
问题的主要原因是客户端192.168.1.6的大量连接使数据库达到了最大processes限制导致用户无法连接，数据库并没有出现宕机。管理员用户仍然能正常登入数据库对数据库进行重启。
