最近碰到一个蛮有启发意义的案例。是数据库监听相关的,但是实际的原因却又出乎意料。
问题的反馈受益于开发同学,一个开发同学在lync上找到我,说现在一个线上业务的数据库访问有些问题,想问问我是否有什么建议。大体了解了下,他们在使用一个非1521的端口,比如端口是1525,他们在业务端看到的错误信息类似下面的样子:
java.sql.SQLException: Io exception: The Network Adapter could not establish the connection
这个问题让我有奇怪,因为这个时间段我们也没有做数据库维护的工作,带着疑问我登录到了这个环境,发现网络确实有一些卡顿,我还在安慰开发同事,是不是网络超时引起的,我再确认一下。
登录到了系统端之后,数据库是可用的,连接数有近800多个,所以说业务应该没有收到什么大的影响,而这位开发同学反馈的1525端口访问有问题是怎么回事呢,我查看了监听器的情况,发现1525的监听端口竟然没开,这就有些奇怪了。难道是谁把这个监听器停了?
显然不合理。所以我们需要查看日志来看看,这个端口是之前就没有开启还是有问题,因为数据库版本较老,是一个10gR2的库,就在$ORACLE_HOME/network/log下找到了日志,找到1525端口对应的日志,发现最近的日志竟然是下面的内容:
Started with pid=11954
Listening on: (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=10.127.xxx)(PORT=1523)))
Error listening on: (ADDRESS=(PROTOCOL=ipc)(PARTIAL=yes)(QUEUESIZE=1))
No longer listening on: (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=10.127.xxx)(PORT=1523)))
TNS-12549: TNS:operating system resource quota exceeded
TNS-12560: TNS:protocol adapter error
TNS-00519: Operating system resource quota exceeded
Solaris Error: 28: No space left on device
这个问题就让我有些疑惑了,首先查看了下磁盘空间,这个分区下的空间使用率是80%左右,不大可能出现空间不够的情况。查看了inode的情况,也没有发现什么问题。怎么会有空间不够的情况呢,难道是oracle的监听有什么特别的设置,这个明显有些说不过去。
然后就尝试手工启动,结果系统层面也迟迟没有响应,稍等了一会,还失败了,最后报出的错误还是空间不够。
那么这个问题到底该怎么解释,我认真梳理了下df -k的全部结果,发现/var目录竟然满了,多么低级的一个错误,当然看到这里,问题的解决思路也一下子清晰起来。
说千遍万遍,竟然是因为空间的问题,这个很不应该啊。为什么会有这种情况呢,系统层面应该是有一个调度任务去删除额外的空间,但是频率还是不高,就在这个间隙出了这个问题,我想看看到底是哪里的日志溢出了,很快就发现是/etc/adm下的日志。
这个目录下的日志怎么会有这么多呢,我想起来前段时间启用了syslog的选项,一些系统层面的操作都能够记录在案,没想到没过多少时间,竟然把这个目录都撑满了。
我对于这个问题的原因还是很感兴趣,毕竟手工删除,或者尽可能频繁的清理日志没有抓住问题的本质,我查看了一圈日志,发现监听成功启动之后,syslog里面的日志竟然生成非常频繁。
几乎是一秒一条记录的速度,这个看起来明显不正常啊。
日志的内容类似下面的形式:
Apr xx 11:11:39 xxxx.com ipmon[17088]: [ID 702911 local0.warning] 11:11:38.740903 e1000g0 @0:1 b 10.127.xxxx -> 10.127.xxxx PR icmp len 20 84 icmp echo/0 IN
几乎每秒一条的记录,这对于系统其实压力是潜在的,我就想这服务器都老态龙钟了,经不起这么折腾,但是通过这个日志该怎么分析原因呢。
首先使用telnet xxx 1523这种方式的日志明显不是上面的输出,那么是不是连接到数据库的频率太高了呢,这个也不大可能,里面有icmp的字样,可以通过listener.log看到数据库中的连接频率远没有日志中那么频繁。这个信息该怎么解释呢,我就换了中思路,如果是我要尝试测试连接,会用哪些方式,除了telnet,ssh,还有一种很常见的就是Ping了。
一想到这里,再来看看日志,还真有点意思,我找了台服务器,模拟了这个过程,发现日志就是这个样子的,所以我就初步定为了问题可能的原因,就是应用服务器没有关闭ping,导致了数据库端的日志量频繁生成,最后导致磁盘空间爆满。
和系统的同学聊了下他们有针对性的进行了排查,还真找到一个脚本,确实在调用ping的操作。禁用之后,这个问题就基本解决了,而且想想我心里还更踏实些。