[20211108]sqlplus 本地登录缓慢.txt

--//昨天看了https://www.xifenfei.com/2021/10/19c-sqlplus-as-sysdba-login-slow.html的帖子，感觉有点不理解。
--//为什么sqlplus / as sysdba 登录缓慢，不应该通过dns解析。我自己也测试看看。

--//首先在11g下测试：
1.环境：
SCOTT@book> @ ver1
PORT_STRING                    VERSION        BANNER
------------------------------ -------------- --------------------------------------------------------------------------------
x86_64/Linux 2.4.xx            11.2.0.4.0     Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production

# grep ^name /etc/resolv.conf
nameserver 88.88.88.88

--//建立一个不存在无法访问的dns。

$ strace -ttTT -f -e connect,poll  sqlplus -s -l / as sysdba <<< exit
17:00:30.552870 connect(7, {sa_family=AF_FILE, path="/var/run/nscd/socket"...}, 110) = -1 ENOENT (No such file or directory) <0.000043>
17:00:30.553373 connect(7, {sa_family=AF_FILE, path="/var/run/nscd/socket"...}, 110) = -1 ENOENT (No such file or directory) <0.000026>
Process 33874 attached
[pid 33874] 17:00:30.600800 connect(6, {sa_family=AF_FILE, path="/var/run/nscd/socket"...}, 110) = -1 ENOENT (No such file or directory) <0.000033>
[pid 33874] 17:00:30.601117 connect(6, {sa_family=AF_FILE, path="/var/run/nscd/socket"...}, 110) = -1 ENOENT (No such file or directory) <0.000028>
[pid 33873] 17:00:30.641735 connect(7, {sa_family=AF_FILE, path="/var/run/nscd/socket"...}, 110) = -1 ENOENT (No such file or directory) <0.000034>
[pid 33873] 17:00:30.642061 connect(7, {sa_family=AF_FILE, path="/var/run/nscd/socket"...}, 110) = -1 ENOENT (No such file or directory) <0.000028>
[pid 33874] 17:00:30.652333 connect(8, {sa_family=AF_FILE, path="/var/run/nscd/socket"...}, 110) = -1 ENOENT (No such file or directory) <0.000034>
[pid 33874] 17:00:30.652645 connect(8, {sa_family=AF_FILE, path="/var/run/nscd/socket"...}, 110) = -1 ENOENT (No such file or directory) <0.000029>
[pid 33874] 17:00:30.653865 connect(8, {sa_family=AF_FILE, path="/dev/log"...}, 110) = 0 <0.000029>
Process 33874 detached

--//很明显11g没有这个问题。即使我开启nscd服务也没有这个问题。
# service nscd status
nscd is stopped
# service nscd start
Starting nscd:  [  OK  ]

$ strace -ttTT -f -e connect,poll  sqlplus -s -l / as sysdba <<< exit
17:04:01.370288 connect(7, {sa_family=AF_FILE, path="/var/run/nscd/socket"...}, 110) = 0 <0.000051>
17:04:01.370736 poll([{fd=7, events=POLLIN|POLLERR|POLLHUP}], 1, 5000) = 1 ([{fd=7, revents=POLLIN|POLLHUP}]) <0.000078>
17:04:01.371276 connect(7, {sa_family=AF_FILE, path="/var/run/nscd/socket"...}, 110) = 0 <0.000033>
17:04:01.371483 poll([{fd=7, events=POLLIN|POLLERR|POLLHUP}], 1, 5000) = 1 ([{fd=7, revents=POLLIN|POLLHUP}]) <0.000625>
Process 34010 attached
[pid 34010] 17:04:01.415819 connect(6, {sa_family=AF_FILE, path="/var/run/nscd/socket"...}, 110) = 0 <0.000031>
[pid 34010] 17:04:01.416058 poll([{fd=6, events=POLLIN|POLLERR|POLLHUP}], 1, 5000) = 1 ([{fd=6, revents=POLLIN|POLLHUP}]) <0.000220>
[pid 34009] 17:04:01.454917 connect(7, {sa_family=AF_FILE, path="/var/run/nscd/socket"...}, 110) = 0 <0.000037>
[pid 34009] 17:04:01.455171 poll([{fd=7, events=POLLIN|POLLERR|POLLHUP}], 1, 5000) = 1 ([{fd=7, revents=POLLIN|POLLHUP}]) <0.000060>
[pid 34009] 17:04:01.455632 connect(7, {sa_family=AF_FILE, path="/var/run/nscd/socket"...}, 110) = 0 <0.000030>
[pid 34009] 17:04:01.455805 poll([{fd=7, events=POLLIN|POLLERR|POLLHUP}], 1, 5000) = 1 ([{fd=7, revents=POLLIN|POLLHUP}]) <0.000466>
[pid 34009] 17:04:01.457129 connect(7, {sa_family=AF_FILE, path="/var/run/nscd/socket"...}, 110) = 0 <0.000028>
[pid 34009] 17:04:01.457327 poll([{fd=7, events=POLLIN|POLLERR|POLLHUP}], 1, 5000) = 1 ([{fd=7, revents=POLLIN|POLLHUP}]) <0.000285>
[pid 34010] 17:04:01.483796 connect(8, {sa_family=AF_FILE, path="/var/run/nscd/socket"...}, 110) = 0 <0.000038>
[pid 34010] 17:04:01.484062 poll([{fd=8, events=POLLIN|POLLERR|POLLHUP}], 1, 5000) = 1 ([{fd=8, revents=POLLIN|POLLHUP}]) <0.000026>
[pid 34010] 17:04:01.484532 connect(8, {sa_family=AF_FILE, path="/var/run/nscd/socket"...}, 110) = 0 <0.000033>
[pid 34010] 17:04:01.484724 poll([{fd=8, events=POLLIN|POLLERR|POLLHUP}], 1, 5000) = 1 ([{fd=8, revents=POLLIN}]) <0.000468>
[pid 34010] 17:04:01.501517 connect(8, {sa_family=AF_FILE, path="/dev/log"...}, 110) = 0 <0.000030>
Process 34010 detached

# service nscd stop
Stopping nscd:   [  OK  ]

2.在18c下测试：
TTT@192.168.2.7:1521/orcl> @ prxx
==============================
PORT_STRING                   : x86_64/Linux 2.4.xx
VERSION                       : 18.0.0.0.0
BANNER                        : Oracle Database 18c Enterprise Edition Release 18.0.0.0.0 - Production
BANNER_FULL                   : Oracle Database 18c Enterprise Edition Release 18.0.0.0.0 - Production
Version 18.3.0.0.0
BANNER_LEGACY                 : Oracle Database 18c Enterprise Edition Release 18.0.0.0.0 - Production
CON_ID                        : 0
PL/SQL procedure successfully completed.

# grep ^name /etc/resolv.conf
nameserver 88.88.88.88

$ strace -tTT -f -e connect,poll sqlplus -s -l / as sysdba <<< exit
17:09:58 connect(6, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory) <0.000335>
17:09:58 connect(6, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory) <0.000219>
17:09:58 connect(9, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory) <0.000242>
17:09:58 connect(9, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory) <0.000269>
17:09:58 connect(9, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("88.88.88.88")}, 16) = 0 <0.000237>
17:09:58 poll([{fd=9, events=POLLOUT}], 1, 0) = 1 ([{fd=9, revents=POLLOUT}]) <0.000186>
17:09:58 poll([{fd=9, events=POLLIN}], 1, 5000) = 0 (Timeout) <5.005259>
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
17:10:03 poll([{fd=9, events=POLLOUT}], 1, 0) = 1 ([{fd=9, revents=POLLOUT}]) <0.000445>
17:10:03 poll([{fd=9, events=POLLIN}], 1, 5000) = 0 (Timeout) <5.001447>
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
strace: Process 25728 attached
[pid 25728] 17:10:08 connect(6, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory) <0.000189>
[pid 25728] 17:10:08 connect(6, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory) <0.000047>
[pid 25699] 17:10:08 connect(9, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("88.88.88.88")}, 16) = 0 <0.000054>
[pid 25699] 17:10:08 poll([{fd=9, events=POLLOUT}], 1, 0) = 1 ([{fd=9, revents=POLLOUT}]) <0.000024>
[pid 25699] 17:10:08 poll([{fd=9, events=POLLIN}], 1, 5000) = 0 (Timeout) <5.004564>
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
[pid 25699] 17:10:13 poll([{fd=9, events=POLLOUT}], 1, 0) = 1 ([{fd=9, revents=POLLOUT}]) <0.000029>
[pid 25699] 17:10:13 poll([{fd=9, events=POLLIN}], 1, 5000) = 0 (Timeout) <5.001399>
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
[pid 25699] 17:10:18 connect(9, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("192.168.x.x")}, 16) = 0 <0.000063>
[pid 25699] 17:10:18 connect(9, {sa_family=AF_UNSPEC, sa_data="\0\0\0\0\0\0\0\0\0\0\0\0\0\0"}, 16) = 0 <0.000027>
[pid 25699] 17:10:18 connect(9, {sa_family=AF_INET, sin_port=htons(0), sin_addr=inet_addr("192.168.122.1")}, 16) = 0 <0.000029>
[pid 25699] 17:10:18 connect(9, {sa_family=AF_INET6, sin6_port=htons(0), inet_pton(AF_INET6, "fe80::8253:dde0:4c74:7177", &sin6_addr), sin6_flowinfo=htonl(0), sin6_scope_id=if_nametoindex("ens192")}, 28) = 0 <0.000072>
[pid 25728] 17:10:18 --- SIGSEGV {si_signo=SIGSEGV, si_code=SEGV_MAPERR, si_addr=NULL} ---
[pid 25728] 17:10:18 connect(4, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory) <0.000314>
[pid 25728] 17:10:18 connect(4, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory) <0.000306>
[pid 25699] 17:10:19 +++ exited with 0 +++
17:10:19 +++ exited with 0 +++

--//每次尝试2次，每次需要5秒超时。基本需要2X秒。
$ time  sqlplus -s -l / as sysdba <<< exit
real    0m20.230s
user    0m0.145s
sys     0m0.022s

--//oracle 每个版本总是在变化，竟然这样登录也要访问dns服务器。

$ strace -tTT -f -o /tmp/a1.txt  sqlplus -s -l / as sysdba <<< exit
--//仔细看跟踪文件，可以发现：
29844 17:35:25 connect(9, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("88.88.88.88")}, 16) = 0 <0.000028>
29844 17:35:25 poll([{fd=9, events=POLLOUT}], 1, 0) = 1 ([{fd=9, revents=POLLOUT}]) <0.000018>
29844 17:35:25 sendto(9, "\261\254\1\0\0\1\0\0\0\0\0\0\5XXXXX\0\0\1\0\1", 23, MSG_NOSIGNAL, NULL, 0) = 23 <0.000091>
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
29844 17:35:25 poll([{fd=9, events=POLLIN}], 1, 5000) = 0 (Timeout) <5.005135>
29844 17:35:30 poll([{fd=9, events=POLLOUT}], 1, 0) = 1 ([{fd=9, revents=POLLOUT}]) <0.000023>
29844 17:35:30 sendto(9, "\261\254\1\0\0\1\0\0\0\0\0\0\5XXXXX\0\0\1\0\1", 23, MSG_NOSIGNAL, NULL, 0) = 23 <0.000089>
29844 17:35:30 poll([{fd=9, events=POLLIN}], 1, 5000) = 0 (Timeout) <5.005104>
29844 17:35:35 close(9)                 = 0 <0.000038>
--//使用dns主要目的是查询解析本机的主机名，实际上问题本质在于linux新版本使用hostnamectl建立主机名，但是它不会修改/etc/hosts文件。
--//修改/etc/hosts文件。

# grep 192 /etc/hosts
192.168.x.y xxxxx

$ strace -tTT -f -e connect,poll sqlplus -s -l / as sysdba <<< exit
17:30:34 connect(6, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory) <0.000087>
17:30:34 connect(6, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory) <0.000055>
17:30:34 connect(9, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory) <0.000077>
17:30:34 connect(9, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory) <0.000060>
strace: Process 27791 attached
[pid 27791] 17:30:34 connect(6, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory) <0.000086>
[pid 27791] 17:30:34 connect(6, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory) <0.000039>
[pid 27791] 17:30:34 --- SIGSEGV {si_signo=SIGSEGV, si_code=SEGV_MAPERR, si_addr=NULL} ---
[pid 27791] 17:30:34 connect(4, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory) <0.000071>
[pid 27791] 17:30:34 connect(4, {sa_family=AF_UNIX, sun_path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory) <0.000037>
[pid 27790] 17:30:35 +++ exited with 0 +++
17:30:35 +++ exited with 0 +++

$ time sqlplus -s -l / as sysdba <<< exit
real    0m0.201s
user    0m0.136s
sys     0m0.021s

--//基本没有延迟。
--//实际上我的测试还导致我的环境lsnrctl status执行缓慢。
$ time strace -f -tTT -o /tmp/aa2.txt  lsnrctl status > /dev/null
real    0m30.148s
user    0m0.047s
sys     0m0.078s

--//检查跟踪文件，可以发现如下内容：
23574 08:47:35 connect(3, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("88.88.88.88")}, 16) = 0 <0.000085>
23574 08:47:35 poll([{fd=3, events=POLLOUT}], 1, 0) = 1 ([{fd=3, revents=POLLOUT}]) <0.000051>
23574 08:47:35 sendmmsg(3, [{msg_hdr={msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="6\21\1\0\0\1\0\0\0\0\0\0\5XXXXX\0\0\1\0\1", iov_len=23}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, msg_len=23}, {msg_hdr={msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="MY\1\0
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
23574 08:47:35 poll([{fd=3, events=POLLIN}], 1, 5000) = 0 (Timeout) <5.001352>
23574 08:47:40 poll([{fd=3, events=POLLOUT}], 1, 0) = 1 ([{fd=3, revents=POLLOUT}]) <0.000029>
23574 08:47:40 sendmmsg(3, [{msg_hdr={msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="6\21\1\0\0\1\0\0\0\0\0\0\5XXXXX\0\0\1\0\1", iov_len=23}], msg_iovlen=1, msg_controllen=0, msg_flags=0}, msg_len=23}, {msg_hdr={msg_name=NULL, msg_namelen=0, msg_iov=[{iov_base="MY\1\0
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
23574 08:47:40 poll([{fd=3, events=POLLIN}], 1, 5000) = 0 (Timeout) <5.002202>
23574 08:47:45 close(3)                 = 0 <0.000055>

--//主要使用dns解析本地主机名，因为监听文件配置的不是使用IP，而是使用主机名，而/etc/hosts文件新的linux版本hostnamectl命
--//令配置主机并不会修改/etc/hosts文件，导致这样的情况出现。
--//我给在我的测试环境在模拟看看11g是否出现类似情况。