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啟動正常。