Linux 环境下， ORACLE 监听启动慢的问题分析

    虚拟机环境，OEL7.2， oracle 12.1。 重启主机后，发现监听程序启动好像将近1分钟。

下面是分析过程：

执行监听启动操作，会hang起来一段时间，最终监听启动成功

[oracle@sky-oel7 ~]$ lsnrctl start

Connecting to (DESCRIPTioN=(ADDRESS=(PROTOCOL=tcp)(HOST=sky-oel7)(PORT=1521)))

STATUS of the LISTENER

------------------------

Alias                     LISTENER

Version                   TNSLSNR for linux: Version 12.1.0.2.0 - Production

Start Date                12-JAN-2016 16:42:57

Uptime                    0 days 0 hr. 0 min. 40 sec

启动耗时40秒。

指定监听的日志等级为16

[oracle@sky-oel7 trace]$ cat /oracle/app/oracle/product/12.1.0/dbhome_1/network/admin/listener.ora

# listener.ora Network Configuration File: /oracle/app/oracle/product/12.1.0/dbhome_1/network/admin/listener.ora

# Generated by Oracle configuration tools.

LISTENER =

  (DESCRIPTION_LIST =

    (DESCRIPTION =

      (ADDRESS = (PROTOCOL = TCP)(HOST = sky-oel7)(PORT = 1521))

    )

  )

TRACE_LEVEL_LISTENER=16

重新启动监听程序，日志

[oracle@sky-oel7 trace]$ tail -f listener.log 

Log messages written to /oracle/app/oracle/diag/tnslsnr/sky-oel7/listener/alert/log.xml

Trace infORMation written to /oracle/app/oracle/diag/tnslsnr/sky-oel7/listener/trace/ora_4179_140717186082304.trc

Trace level is currently 16

Started with pid=4179

Listening on: (DESCRIPTION=(ADDRESS=(PROTOCOL=tcp)(HOST=sky-oel7)(PORT=1521)))

TIMESTAMP * CONNECT DATA [* PROTOCOL INFO] * EVENT [* SID] * RETURN CODE

WARNING: Subscription for node down event still pending

12-JAN-2016 16:10:14 * (CONNECT_DATA=(CID=(PROGRAM=)(HOST=sky-oel7)(USER=oracle))(COMMAND=status)(ARGUMENTS=64)(SERVICE=LISTENER)(VERSION=202375680)) * status * 0

[oracle@sky-oel7 admin]$ vi /oracle/app/oracle/diag/tnslsnr/sky-oel7/listener/trace/ora_4179_140717186082304.trc

2016-01-12 16:09:34.211259 : nttcnp:binding an address to a Socket.

2016-01-12 16:09:34.211275 : nttcnp:listening on a bound socket (queue size = 128).

2016-01-12 16:09:34.211324 : nttcnp:getting sockname

2016-01-12 16:09:34.211342 : nttcnp:getting peername

2016-01-12 16:09:34.211355 : nttcnp:exit

2016-01-12 16:09:34.211368 : snlinGetAddrInfo:entry

2016-01-12 16:10:14.256096 : snlinGetAddrInfo:getaddrinfo() failed with error -3

2016-01-12 16:10:14.256193 : snlinGetAddrInfo:exit

2016-01-12 16:10:14.256215 : nttcon:exit

2016-01-12 16:10:14.256241 : nsopen:transport is open

2016-01-12 16:10:14.256261 : nsoptions:entry

没有更多的可用信息。

通过strace进行进程启动信息分析

[oracle@sky-oel7 ~]$ strace -f -t -o ~/listener.trc lsnrctl start

查看strace日志信息

5042  16:42:57 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 13

5042  16:42:57 connect(13, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("172.24.97.1")}, 16) = 0

5042  16:42:57 poll([{fd=13, events=POLLOUT}], 1, 0) = 1 ([{fd=13, revents=POLLOUT}])

5042  16:42:57 sendto(13, ":\26\1\0\0\1\0\0\0\0\0\0\10sky-oel7\tworkgroup\0"..., 36, MSG_NOSIGNAL, NULL, 0) = 36

5042  16:42:57 poll([{fd=13, events=POLLIN}], 1, 5000) = 0 (Timeout)

5042  16:43:02 socket(PF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 14

5042  16:43:02 connect(14, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("192.168.191.1")}, 16) = 0

5042  16:43:02 poll([{fd=14, events=POLLOUT}], 1, 0) = 1 ([{fd=14, revents=POLLOUT}])

5042  16:43:02 sendto(14, ":\26\1\0\0\1\0\0\0\0\0\0\10sky-oel7\tworkgroup\0"..., 36, MSG_NOSIGNAL, NULL, 0) = 36

5042  16:43:02 poll([{fd=14, events=POLLIN}], 1, 5000) = 0 (Timeout)

上面的信息看出，是由于地址解析失败造成网络超时。

这些地址都是安装时，自动产生的DNS地址信息，由于环境发生变化,DNS地址不同，造成访问操作

[root@sky-oel7 ~]# cat /etc/resolv.conf 

# Generated by NetworkManager

search workgroup

nameserver 172.24.97.1

nameserver 192.168.191.1

屏蔽这些地址后，listener启动正常。