某省的数据库时不时的发生侦听挂死的现象。我们来看看具体的情况:
当出现侦听挂死的时候,sqlplus登录会出现如下报错:
1 2 3 4 5 6 7 8 9 10 |
$ sqlplus user/pwd@tnsnames SQL*Plus: Release 9.2.0.6.0 - Production on Sun Jun 28 11:43:32 2009 Copyright (c) 1982, 2002, Oracle Corporation. All rights reserved. ERROR: ORA-12535: TNS:operation timed out $ |
而此时,可以看到listener.log中的内容为:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 |
…… 28-JUN-2009 11:45:01 * 1168 TNS-01168: Cannot allocate memory 28-JUN-2009 11:45:01 * 1168 TNS-01168: Cannot allocate memory 28-JUN-2009 11:45:01 * 1168 TNS-01168: Cannot allocate memory 28-JUN-2009 11:45:01 * 1168 TNS-01168: Cannot allocate memory 28-JUN-2009 11:45:01 * 1168 TNS-01168: Cannot allocate memory 28-JUN-2009 11:45:01 * 1168 TNS-01168: Cannot allocate memory 28-JUN-2009 11:45:01 * 1168 TNS-01168: Cannot allocate memory 28-JUN-2009 11:45:01 * 1168 TNS-01168: Cannot allocate memory 28-JUN-2009 11:45:01 * 1168 TNS-01168: Cannot allocate memory …… |
检查当时的主机内存情况:
1 2 3 4 5 6 7 8 9 10 11 12 13 |
$ getconf PAGE_SIZE 4096 $ vmstat 2 5 procs memory page faults cpu $ vmstat 2 5 procs memory page faults cpu r b w avm free re at pi po fr de sr in sy cs us sy id 4 1 0 1890222 1189872 47 5 0 0 0 0 1 7142 29856 2759 5 2 93 4 1 0 1890222 1189816 8 0 0 0 0 0 0 7670 272634 3623 10 4 86 3 2 0 1881426 1189816 4 0 0 0 0 0 0 7245 264305 3001 7 2 90 3 2 0 1881426 1189816 2 0 0 0 0 0 0 6860 256687 2410 7 3 90 3 2 0 1881426 1189816 0 0 0 0 0 0 0 6562 255745 2033 7 3 90 $ |
我们看到其实还是有大约4.4G的内存剩余的。
该数据库由于要求安全加固,在侦听的sqlnet.ora文件中设置了IP鉴权,配置如下:
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 |
$ cat sqlnet.ora # SQLNET.ORA Network Configuration File: /oracle/app/oracle/product/9.2.0/network/admin/sqlnet.ora # Generated by Oracle configuration tools. NAMES.DIRECTORY_PATH= (TNSNAMES, ONAMES, HOSTNAME) TCP.VALIDNODE_CHECKING=yes TCP.INVITED_NODES=(11.22.33.39, 11.22.33.40, 11.22.33.41, 11.22.33.42, 11.22.33.43, 11.22.33.44, …… 11.22.33.88) |
当时初步的怀疑是listener.log太大(已经有2.1G多),就用>listener.log的方式先把listenr.log清空了,但是发现还是挂死,还是无法连接,为了先恢复应用,尝试重启侦听。
但是lnsrctl stop的方式也挂死,没办法,只能用kill -9的方式杀掉tnslsnr进程,再次lsnrctl start,恢复正常。
很奇怪的一个,为什么内存还有大量剩余的情况下,侦听会挂死?
提交了一个tar给oracle,oracle给出的解释是因为listener.log太大,所以挂死的。oracle建议控制listener.log的大小低于30M。
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 |
UPDATE ======= Hi , Having lots of free space will not solve the purpuse here, If listener.log is big then It take time to open it which causes hang. Try to keep it in few MBs (e.g below 30MB) Thanks, Rishi STATUS ======= @CUS -- Waiting for requested information |
虽然我不是很相信这个解释,我是比较怀疑IP鉴权引起的问题,因为同时设置IP鉴权的2个省,一个没事,一个有事。出事的那个省,在hang住之前的listener.log中可以发现大量的拒连信息:
1 2 3 4 5 6 7 8 9 |
28-JUN-2009 11:45:34 * 12546 TNS-12546: TNS:permission denied TNS-12560: TNS:protocol adapter error TNS-00516: Permission denied 28-JUN-2009 11:45:35 * 12546 TNS-12546: TNS:permission denied TNS-12560: TNS:protocol adapter error TNS-00516: Permission denied |
不过我还是按照建议进行了配置:将listener.log配置成不写日志:LOGGING_LISTENER=OFF
9天后,再次发生侦听挂死的现象。此时listener.log的大小是0.幸好当时我要求不关闭tar,进行监控2个月。我再次update了这个tar,并且提醒oracle,IP鉴权和侦听的挂死是否有关系,是否有类似的bug?
oracle 2天时间没回我,没办法,打800进行escalate tar,并且要求SDM关注该tar。
最后,oracle确认有2个类似的bug:Bug: 3896886 和Bug 3908058
在8i中,由于配置了protocol.ora validnode_checking,当不在IP列表范围的机器尝试连接数据时,将导致内存泄漏。
我确实配置了类似于像8i的IP鉴权,也确实存在不在IP信任列表中的连接。通过trace找到这些IP。在sqlnet.ora中添加:
1 2 3 4 5 |
TRACE_FILE_LISTENER = LISTENER.TRC TRACE_DIRECTORY_LISTENER = /tmp/lsnrtrace/ TRACE_LEVEL_LISTENER = SUPPORT TRACE_FILELEN_LISTENER=10240 TRACE_FILENO_LISTENER=10 |
然后lsnrctl reload。
1 2 3 4 5 6 7 8 |
$ grep Denied listener1.trc [000001 13-JUL-2009 14:26:10:964] nttvlser: Denied Entry: 11.22.44.33 [000001 13-JUL-2009 14:26:14:028] nttvlser: Denied Entry: 11.22.44.55 [000001 13-JUL-2009 14:26:14:464] nttvlser: Denied Entry: 11.22.44.33 [000001 13-JUL-2009 14:26:17:528] nttvlser: Denied Entry: 11.22.44.33 [000001 13-JUL-2009 14:26:17:964] nttvlser: Denied Entry: 11.22.44.33 [000001 13-JUL-2009 14:26:21:028] nttvlser: Denied Entry: 11.22.44.55 …… |
找到了2个对应的IP,和主机工程师联系后,发现这2个IP可以不连数据库,在防火墙上直接将其拦截。
目前已经半个月过去了,再没有发生侦听挂死的现象。
一条评论
如果不经过sdm,你做sr的escalation ,是没用的
唯一的escalation sr的方法就是使劲的骚扰sdm