InetAddress.getLocalHost()深入分析

InetAddress.getLocalHost()深入分析

背景

​ 最近我们一个线上的Spring boot应用启动特别慢,达到六七分钟,但是在测试环境启动很正常,基本上30秒左右,而且测试环境的配置比线上低很多。经过一天的排查对比分析,解决方案是在机器的/etc/hosts文件中配置IP与主机名的映射,但是为什么会造成这种情况就不得而知了,所以在后面深入分析了一下原因。

问题原因

​ 从启动日志上来看基本上都是在有网络调用的地方耗时比较长,比如启动的时候会连接zookeeper以及mysql等组件,又结合修改/etc/hosts配置文件能够解决问题,所以怀疑是不是解析主机名的时候出现了问题。所以写了一段测试代码,如下:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
public class DemoApplication {

public static void main(String[] args) {
//#1
try {
long begin = System.currentTimeMillis();
InetAddress hostName = InetAddress.getLocalHost();
System.out.println(hostName.getHostName() + " : " + hostName.getHostAddress());
System.out.println("It takes " + (System.currentTimeMillis() - begin) + " ms");
} catch (UnknownHostException e) {
e.printStackTrace();
}
//#2
try {
long begin = System.currentTimeMillis();
InetAddress hostName = InetAddress.getLocalHost();
System.out.println(hostName.getHostName() + " : " + hostName.getHostAddress());
System.out.println("It takes " + (System.currentTimeMillis() - begin) + " ms");
} catch (UnknownHostException e) {
e.printStackTrace();
}
//#3
try {
long begin = System.currentTimeMillis();
InetAddress hostName = InetAddress.getByName("主机名");
System.out.println(hostName.getHostName() + " : " + hostName.getHostAddress());
System.out.println("It takes " + (System.currentTimeMillis() - begin) + " ms");
} catch (UnknownHostException e) {
e.printStackTrace();
}
}
}

​ 将这段程序放在线上机器执行,执行结果如下:

It takes 19665 ms
It takes 14832 ms
It takes 0 ms

​ 其实很容易看出InetAddress.getLocalHost()这个方法肯定是有问题的,但是#3这段代码我是直接用InetAddress.getByName(“主机名”);会很快。接着对InetAddress.getLocalHost()和InetAddress.getByName(“主机名”)的源码进行debug,大家可以看到这两个方法都会走到InetAddress.getAddressesFromNameService方法,这个方法里有一个比较重要的是addresses = nameService.lookupAllHostAddr(host); 而这个方法最终会调用Inet4AddressImpl里的public native InetAddress[] lookupAllHostAddr(String hostname) throws UnknownHostException; 但是InetAddress.getLocalHost()方法在之前有这么一段处理String local = impl.getLocalHostName();取主机名,最终调用的是Inet4AddressImpl里的public native String getLocalHostName() throws UnknownHostException; 所以我们初步定位就是getLocalHostName这个native方法耗时了。 这一块说的比较绕,且没有贴出源码,相信大家只要会debug都能把这个调用关系梳理清楚。

​ 但是走到这里我们是不是线索就断了呢,因为最终调用native方法我们debug不了,不知道getLocalHostName这个方法究竟做了什么。别急,我们还有终极武器,从OpenJDK中寻求真相。大家可以从http://hg.openjdk.java.net/jdk8 这里下载源码,然后找到我们想要的方法,在/src/solaris/native/java/net这里能找到Inet4AddressImpl的实现(基本上Linux平台相关的代码都在solaris目录下),我们找到getLocalHostName的实现,如下所示:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
JNIEXPORT jstring JNICALL
Java_java_net_Inet4AddressImpl_getLocalHostName(JNIEnv *env, jobject this) {
char hostname[NI_MAXHOST+1];

hostname[0] = '\0';
//#1
if (JVM_GetHostName(hostname, NI_MAXHOST)) {
/* Something went wrong, maybe networking is not setup? */
strcpy(hostname, "localhost");
} else {
struct addrinfo hints, *res;
int error;

memset(&hints, 0, sizeof(hints));
hints.ai_flags = AI_CANONNAME;
hints.ai_family = AF_UNSPEC;

//#2
error = getaddrinfo(hostname, NULL, &hints, &res);

if (error == 0) {
/* host is known to name service */
//#3
error = getnameinfo(res->ai_addr,
res->ai_addrlen,
hostname,
NI_MAXHOST,
NULL,
0,
NI_NAMEREQD);

/* if getnameinfo fails hostname is still the value
from gethostname */

freeaddrinfo(res);
}
}
return (*env)->NewStringUTF(env, hostname);
}

​ 基本上分为3步,第一步获取主机名,也就是#1的部分,这块是调了JVM的GetHostName方法,这个方法最终会调用到gethostname这个系统函数;第二步#2是根据主机名获取IP,getaddrinfo是linux的系统函数;第三步#3是根据ip获取主机名或者域名,getnameinfo也是linux的系统函数。所以耗时应该是这三个环节中的某一个出现了问题。我们把这一段C代码放在linux来运行,所以我写了下面这段测试方法testGethostname.c,编译gcc testGethostname.c -o testGethostname。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
#include <stdio.h>
#include <stdlib.h>
#include <netdb.h>

int main(void) {
char hostname[1025];

hostname[0] = '\0';
gethostname(hostname, 1024);

struct addrinfo hints, *res;
int error;

hostname[1025] = '\0';
memset(&hints, 0, sizeof(hints));
hints.ai_flags = AI_CANONNAME;
hints.ai_family = AF_INET;

error = getaddrinfo(hostname, NULL, &hints, &res);

//#3
if (error == 0) {
getnameinfo(res->ai_addr,
res->ai_addrlen,
hostname,
NI_MAXHOST,
NULL,
0,
NI_NUMERICHOST);


freeaddrinfo(res);
}
}

​ 运行过程还是会比较慢,所以我把三步分别进行注释,当把#3后面的代码注释掉的时候,程序运行起来就很快了。追到这里,其实就知道了是getnameinfo这个耗时,getnameinfo官方解释是it converts a socket address to a corresponding host and service,其实就是将相应的socket地址转换成主机名和域名。这里为什么会耗时呢。我也没有再去跟getnameinfo这个是怎么实现的,因为发现了一个比较好用的工具strace,在Linux用来跟踪系统调用。所以我执行了strace ./testGethostname,结果如下,没有截取完整:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
connect(3, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("180.76.76.76")}, 16) = 0
poll([{fd=3, events=POLLOUT}], 1, 0) = 1 ([{fd=3, revents=POLLOUT}])
sendto(3, "\227\21\1\0\0\1\0\0\242\7in-add"..., 43, MSG_NOSIGNAL, NULL, 0) = 43
poll([{fd=3, events=POLLIN}], 1, 5000) = 0 (Timeout)
socket(AF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 4
connect(4, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("219.141.136.10")}, 16) = 0
poll([{fd=4, events=POLLOUT}], 1, 0) = 1 ([{fd=4, revents=POLLOUT}])
sendto(4, "\227\21\1\0\0\1\0\0\0\0\2\7in-add"..., 43, MSG_NOSIGNAL, NULL, 0) = 43
poll([{fd=4, events=POLLIN}], 1, 3000) = 0 (Timeout)
socket(AF_INET, SOCK_DGRAM|SOCK_NONBLOCK, IPPROTO_IP) = 5
connect(5, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("223.5.5.5")}, 16) = 0
poll([{fd=5, events=POLLOUT}], 1, 0) = 1 ([{fd=5, revents=POLLOUT}])
sendto(5, "\227\21\1\0\0\1\0\0\0\0\0\0\00242\7in-add"..., 43, MSG_NOSIGNAL, NULL, 0) = 43
poll([{fd=5, events=POLLIN}], 1, 6000) = 0 (Timeout)
poll([{fd=3, events=POLLOUT}], 1, 0) = 1 ([{fd=3, revents=POLLOUT}])
sendto(3, "\227\21\1\0\0\1\0\0\0\0\0\0\003\7in-add"..., 43, MSG_NOSIGNAL, NULL, 0) = 43
poll([{fd=3, events=POLLIN}], 1, 5000) = 0 (Timeout)
poll([{fd=4, events=POLLOUT}], 1, 0) = 1 ([{fd=4, revents=POLLOUT}])
sendto(4, "\227\21\1\0\0\1\0\0\0\0\0\0\062\00242\7in-add"..., 43, MSG_NOSIGNAL, NULL, 0) = 43
poll([{fd=4, events=POLLIN}], 1, 3000) = 1 ([{fd=4, revents=POLLIN}])
ioctl(4, FIONREAD, [43]) = 0
recvfrom(4, "\227\21\201\202\0\1\0\0\0\0\0\0\00310\7in-add"..., 1024, 0, {sa_family=AF_INET, sin_port=htons(53), sin_addr=inet_addr("219.141.136.10")}, [16]) = 43

​ 从这个结果中可以看到这里会在DNS服务器(因为我们的机器在/etc/resolv.conf中配置了三个域名服务器)去查IP对应的host,而且都是Timeout,这里其实也就找到最终原因了,就是这里耗时。分析到这里也就结束了。

问题

​ 上面虽然分析了过程,但也有几个问题需要说一下。

​ 1、名称的解析顺序是怎样的呢?

​ 答案在/etc/nsswitch.conf配置文件中的“hosts”配置,centos7一般配置为files dns myhostname,而centos一般配置为files dns myhostname,files就是/etc/hosts文件,dns就是通过dns服务器进行解析,myhostname 只返回本机配置的公共IP地址,具体解释参https://www.unix.com/man-page/centos/8/nss-myhostname/

​ 2、getnameinfo这个函数为什么会这么慢?

​ 因为getnameinfo会走到DNS解析,只不过是通过IP解析成host,也即域名的反向解析(你可以执行一下)。因为我们机器配置的第一个公共IP是一个外网IP,而用nslookup [外网ip]测了一下,DNS Server会返回SERVFAIL,也有connection time out,但如果用nslookup [内网ip],DNS Server会很快返回NXDOMAIN。所以这个和DNS内部实现又关系,具体的还没看。

总结

​ 这次问题排查前前后后花了大概一周的时间,从这中间也学了很多东西,从JVM到Linux到C语言,是一段比较艰辛的过程,希望这是一次新的开始。

参考资料

nss-myhostname
getnameinfo
getaddrinfo