searchusermenu
  • 发布文章
  • 消息中心
点赞
收藏
评论
分享
原创

Spring Boot应用在特定环境启动缓慢的原因分析

2023-03-27 06:58:25
244
0

问题现象

同一个Spring Boot应用,在测试环境启动大约需要30秒,而在生产环境中,启动耗时超过1分钟,启动后应用使用过程无其他异常情况。

初步原因分析

测试环境与生产环境使用了相同的操作系统镜像,且生产环境主机配置更高,经检查应用部署主机与数据库、中间件的网络连接没有问题,基本排除操作系统版本差异、主机配置差异、网络等原因。

对比测试环境和生产环境的启动日志,生产环境的启动日志多了如下警告日志:

WARN  o.s.boot.StartupInfoLogger - InetAddress.getLocalHost().getHostName() took 30032 milliseconds to respond. Please verify your network configuration.

常见解决办法

网络上对该问题常见的解决办法为修改系统/etc/hosts文件,配置hostname到回环地址。例如主机的hostname为centos-dev1时,在127.0.0.1和::1两行末尾加上centos-dev1:

127.0.0.1   localhost localhost.localdomain localhost4 localhost4.localdomain4 centos-dev1
::1         localhost localhost.localdomain localhost6 localhost6.localdomain6 centos-dev1

加上该配置之后,重启Spring Boot应用,可以看到启动时间降低到了30秒左右,与测试环境相当,启动日志中的告警也不存在了。

新的疑问

通过在生产环境配置/etc/hosts文件虽然能解决该问题,但是测试环境并没有在/etc/hosts中添加hostname,启动速度却没有变慢。因此,该配置并不是启动缓慢的根本原因。

代码分析

通过警告日志,查看org.springframework.boot.StartupInfoLogger类源代码,可以发现在Spring Boot应用启动时,会在该类中同步调用InetAddress.getLocalHost().getHostName()方法打印应用启动信息。InetAddress.getLocalHost().getHostName()方法的调用经历了几次修改:

Spring Boot 1.x.x:

 private String getOn() {
  return getValue(" on ", new Callable<Object>() {
   @Override
   public Object call() throws Exception {
    return InetAddress.getLocalHost().getHostName();
   }
  });
 }

Spring Boot 2.0.x - 2.1.x:

 private String getOn() {
  return getValue(" on ", () -> InetAddress.getLocalHost().getHostName());
 }

Spring Boot 2.2.x - 2.7.x:

 private void appendOn(StringBuilder message) {
  long startTime = System.currentTimeMillis();
  append(message, "on ", () -> InetAddress.getLocalHost().getHostName());
  long resolveTime = System.currentTimeMillis() - startTime;
  if (resolveTime > HOST_NAME_RESOLVE_THRESHOLD) {
   logger.warn(LogMessage.of(() -> {
    StringBuilder warning = new StringBuilder();
    warning.append("InetAddress.getLocalHost().getHostName() took ");
    warning.append(resolveTime);
    warning.append(" milliseconds to respond.");
    warning.append(" Please verify your network configuration");
    if (System.getProperty("os.name").toLowerCase().contains("mac")) {
     warning.append(" (macOS machines may need to add entries to /etc/hosts)");
    }
    warning.append(".");
    return warning;
   }));
  }
 }

Spring Boot 3.0.x:

无InetAddress.getLocalHost().getHostName()调用。

其中第一次修改仅将Callable匿名类改为Lambda表达式,本质没有变化;第二次修改则是加入了我们在生产环境中看到的告警日志,当InetAddress.getLocalHost().getHostName()的执行时间超过HOST_NAME_RESOLVE_THRESHOLD(200毫秒)时,打印该日志;第三次修改则是完全移除了InetAddress.getLocalHost().getHostName()的调用。

为确认是InetAddress.getLocalHost().getHostName()的调用影响了生产环境的启动速度,编写一个简单的Java程序进行测试:

import java.net.InetAddress;
import java.net.UnknownHostException;

public class HostnameTest {

    public static void main(String[] args) throws UnknownHostException {
        long start = System.currentTimeMillis();
        InetAddress localHost = InetAddress.getLocalHost();
        long end = System.currentTimeMillis();
        System.out.println("getLocalHost time cost: " + (end - start));
        start = System.currentTimeMillis();
        String hostName = localHost.getHostName();
        end = System.currentTimeMillis();
        System.out.println("getHostName time cost: " + (end - start));
        System.out.println(hostName);
    }

}

分别在测试环境、生产环境(未在/etc/hosts文件中配置hostname)、生产环境(在/etc/hosts文件中配置hostname)中执行结果如下:

# 测试环境(未在/etc/hosts文件中配置hostname)
$ java HostnameTest
getLocalHost time cost: 60
getHostName time cost: 0
centos-dev1

# 生产环境(未在/etc/hosts文件中配置hostname)
$ java HostnameTest
getLocalHost time cost: 10023
getHostName time cost: 0
centos-prod1

# 生产环境(在/etc/hosts文件中配置hostname)
$ java HostnameTest
getLocalHost time cost: 16
getHostName time cost: 0
centos-prod1

问题已经基本上确定是InetAddress.getLocalHost()在生产环境未在/etc/hosts文件中配置hostname时执行耗时高导致的。

使用 Arthas 工具的 trace命令看看InetAddress.getLocalHost()执行链路耗时(必须在Arthas中执行options unsafe true才能追踪java.*包下面的类),最终可以定位到java.net.InetAddressImpl:lookupAllHostAddr()方法。

java.net.InetAddressImpl是个接口,它的实现有java.net.Inet4AddressImpl和java.net.Inet6AddressImpl,其中的lookupAllHostAddr都是native方法。通过Java代码调试可知,此处调用lookupAllHostAddr方法的参数为主机的hostname,该方法通过系统调用查询hostname对应的IP地址,这是一个域名解析过程。

问题根源

Linux的域名解析过程为,先查找主机/etc/hosts文件,如果找到相应记录则立即返回,如果找不到相应的记录,则通过/etc/resolv.conf中配置的DNS服务器查找。

经对比,测试环境主机与/etc/resolv.conf中配置的DNS服务器网络是相通的,而生产环境做了网络安全加固,无法连接到/etc/resolv.conf中配置的DNS服务器,因此InetAddress.getLocalHost()的调用会一直等待到DNS服务器连接超时(默认5秒超时,尝试连接2次),最终导致Spring Boot应用启动时间增加。

在/etc/hosts文件中配置hostname之后,域名解析直接返回结果,无需到DNS服务器进行查询,因此从测试代码的执行结果看,生产环境(在/etc/hosts文件中配置hostname)的性能还更优于测试环境(未在/etc/hosts文件中配置hostname)。

解决办法

综上所述,要解决以上生产环境Spring Boot启动速度慢的问题,有以下办法:

1. 在/etc/hosts文件中配置hostname
2. 在/etc/resolv.conf文件中配置可以正常访问的DNS服务器
3. 在/etc/resolv.conf文件中移除无法访问的DNS服务器
4. 升级Spring Boot到3.0.x以上版本(JDK需要相应升级到17,对遗留项目风险较高)

0条评论
0 / 1000
杨济嘉
2文章数
0粉丝数
杨济嘉
2 文章 | 0 粉丝
杨济嘉
2文章数
0粉丝数
杨济嘉
2 文章 | 0 粉丝
原创

Spring Boot应用在特定环境启动缓慢的原因分析

2023-03-27 06:58:25
244
0

问题现象

同一个Spring Boot应用,在测试环境启动大约需要30秒,而在生产环境中,启动耗时超过1分钟,启动后应用使用过程无其他异常情况。

初步原因分析

测试环境与生产环境使用了相同的操作系统镜像,且生产环境主机配置更高,经检查应用部署主机与数据库、中间件的网络连接没有问题,基本排除操作系统版本差异、主机配置差异、网络等原因。

对比测试环境和生产环境的启动日志,生产环境的启动日志多了如下警告日志:

WARN  o.s.boot.StartupInfoLogger - InetAddress.getLocalHost().getHostName() took 30032 milliseconds to respond. Please verify your network configuration.

常见解决办法

网络上对该问题常见的解决办法为修改系统/etc/hosts文件,配置hostname到回环地址。例如主机的hostname为centos-dev1时,在127.0.0.1和::1两行末尾加上centos-dev1:

127.0.0.1   localhost localhost.localdomain localhost4 localhost4.localdomain4 centos-dev1
::1         localhost localhost.localdomain localhost6 localhost6.localdomain6 centos-dev1

加上该配置之后,重启Spring Boot应用,可以看到启动时间降低到了30秒左右,与测试环境相当,启动日志中的告警也不存在了。

新的疑问

通过在生产环境配置/etc/hosts文件虽然能解决该问题,但是测试环境并没有在/etc/hosts中添加hostname,启动速度却没有变慢。因此,该配置并不是启动缓慢的根本原因。

代码分析

通过警告日志,查看org.springframework.boot.StartupInfoLogger类源代码,可以发现在Spring Boot应用启动时,会在该类中同步调用InetAddress.getLocalHost().getHostName()方法打印应用启动信息。InetAddress.getLocalHost().getHostName()方法的调用经历了几次修改:

Spring Boot 1.x.x:

 private String getOn() {
  return getValue(" on ", new Callable<Object>() {
   @Override
   public Object call() throws Exception {
    return InetAddress.getLocalHost().getHostName();
   }
  });
 }

Spring Boot 2.0.x - 2.1.x:

 private String getOn() {
  return getValue(" on ", () -> InetAddress.getLocalHost().getHostName());
 }

Spring Boot 2.2.x - 2.7.x:

 private void appendOn(StringBuilder message) {
  long startTime = System.currentTimeMillis();
  append(message, "on ", () -> InetAddress.getLocalHost().getHostName());
  long resolveTime = System.currentTimeMillis() - startTime;
  if (resolveTime > HOST_NAME_RESOLVE_THRESHOLD) {
   logger.warn(LogMessage.of(() -> {
    StringBuilder warning = new StringBuilder();
    warning.append("InetAddress.getLocalHost().getHostName() took ");
    warning.append(resolveTime);
    warning.append(" milliseconds to respond.");
    warning.append(" Please verify your network configuration");
    if (System.getProperty("os.name").toLowerCase().contains("mac")) {
     warning.append(" (macOS machines may need to add entries to /etc/hosts)");
    }
    warning.append(".");
    return warning;
   }));
  }
 }

Spring Boot 3.0.x:

无InetAddress.getLocalHost().getHostName()调用。

其中第一次修改仅将Callable匿名类改为Lambda表达式,本质没有变化;第二次修改则是加入了我们在生产环境中看到的告警日志,当InetAddress.getLocalHost().getHostName()的执行时间超过HOST_NAME_RESOLVE_THRESHOLD(200毫秒)时,打印该日志;第三次修改则是完全移除了InetAddress.getLocalHost().getHostName()的调用。

为确认是InetAddress.getLocalHost().getHostName()的调用影响了生产环境的启动速度,编写一个简单的Java程序进行测试:

import java.net.InetAddress;
import java.net.UnknownHostException;

public class HostnameTest {

    public static void main(String[] args) throws UnknownHostException {
        long start = System.currentTimeMillis();
        InetAddress localHost = InetAddress.getLocalHost();
        long end = System.currentTimeMillis();
        System.out.println("getLocalHost time cost: " + (end - start));
        start = System.currentTimeMillis();
        String hostName = localHost.getHostName();
        end = System.currentTimeMillis();
        System.out.println("getHostName time cost: " + (end - start));
        System.out.println(hostName);
    }

}

分别在测试环境、生产环境(未在/etc/hosts文件中配置hostname)、生产环境(在/etc/hosts文件中配置hostname)中执行结果如下:

# 测试环境(未在/etc/hosts文件中配置hostname)
$ java HostnameTest
getLocalHost time cost: 60
getHostName time cost: 0
centos-dev1

# 生产环境(未在/etc/hosts文件中配置hostname)
$ java HostnameTest
getLocalHost time cost: 10023
getHostName time cost: 0
centos-prod1

# 生产环境(在/etc/hosts文件中配置hostname)
$ java HostnameTest
getLocalHost time cost: 16
getHostName time cost: 0
centos-prod1

问题已经基本上确定是InetAddress.getLocalHost()在生产环境未在/etc/hosts文件中配置hostname时执行耗时高导致的。

使用 Arthas 工具的 trace命令看看InetAddress.getLocalHost()执行链路耗时(必须在Arthas中执行options unsafe true才能追踪java.*包下面的类),最终可以定位到java.net.InetAddressImpl:lookupAllHostAddr()方法。

java.net.InetAddressImpl是个接口,它的实现有java.net.Inet4AddressImpl和java.net.Inet6AddressImpl,其中的lookupAllHostAddr都是native方法。通过Java代码调试可知,此处调用lookupAllHostAddr方法的参数为主机的hostname,该方法通过系统调用查询hostname对应的IP地址,这是一个域名解析过程。

问题根源

Linux的域名解析过程为,先查找主机/etc/hosts文件,如果找到相应记录则立即返回,如果找不到相应的记录,则通过/etc/resolv.conf中配置的DNS服务器查找。

经对比,测试环境主机与/etc/resolv.conf中配置的DNS服务器网络是相通的,而生产环境做了网络安全加固,无法连接到/etc/resolv.conf中配置的DNS服务器,因此InetAddress.getLocalHost()的调用会一直等待到DNS服务器连接超时(默认5秒超时,尝试连接2次),最终导致Spring Boot应用启动时间增加。

在/etc/hosts文件中配置hostname之后,域名解析直接返回结果,无需到DNS服务器进行查询,因此从测试代码的执行结果看,生产环境(在/etc/hosts文件中配置hostname)的性能还更优于测试环境(未在/etc/hosts文件中配置hostname)。

解决办法

综上所述,要解决以上生产环境Spring Boot启动速度慢的问题,有以下办法:

1. 在/etc/hosts文件中配置hostname
2. 在/etc/resolv.conf文件中配置可以正常访问的DNS服务器
3. 在/etc/resolv.conf文件中移除无法访问的DNS服务器
4. 升级Spring Boot到3.0.x以上版本(JDK需要相应升级到17,对遗留项目风险较高)

文章来自个人专栏
文章 | 订阅
0条评论
0 / 1000
请输入你的评论
0
0