为啥 springboot 这么多版本了，这个问题还是没解决还是只有我遇到这情况？

V2EX = way to explore

V2EX 是一个关于分享和探索的地方

已注册用户请登录

这是一个创建于 1199 天前的主题，其中的信息可能已经有所发展或是发生改变。

问题：每次启动完 springboot 后，无论代码写的多么简单，第一个接口请求总是特别耗时，后续该项目的任何接口请求就特别快。

@SpringBootApplication
@RestController
public class DemoApplication {
   public static void main(String[] args) {
      SpringApplication.run(DemoApplication.class, args);
   }
   
   @GetMapping(path = "/test")
   public String testRequest() {
     return "123";
   }
   
   @PostMapping(path = "/test2")
   public String testRequest2() {
     return "456";
   }
}

就即使这么简单的代码，项目启动后，不论先请求哪一个接口，总是特别耗时，我本地测试第一次总是 150ms 左右，第二次就是 5 、6ms 。

什么懒加载啥的都试了，没有任何效果。

有人有遇到这个情况吗？

32 条回复 • 2021-01-08 02:11:58 +08:00

crclz

2021-01-06 11:12:30 +08:00

你看看 chrome 或者 postman 的时间开销，先确定是客户端的开销，还是服务端的开销。

我之前就遇到过类似的，知道我发现 dns 开销 200ms 。

wysnylc

2021-01-06 11:14:30 +08:00

[Spring boot 第一次请求很慢问题]( https://blog.csdn.net/wysnxzm/article/details/103306665)
你的问题

shayang888

2021-01-06 11:30:59 +08:00

@crclz 我刚试了下用 2 个客户端来访问，先用 postman 结果 160 多 ms 然后用 chrome 访问 20ms 换一遍用 chrome 160ms 然后 postman 10ms

chendy

2021-01-06 11:34:21 +08:00

都这样，但是因为真的只影响首次请求所以可能大家并不在意
而且这不是 spring-boot 的问题，是 spring-mvc 的问题，早年以为是 load-on-startup 的影响，后来发现并不是

暴力解决方法是写个 ApplicationRunner 或者其他东西，应用启动之后自己请求自己一次，完成初始化
还可以用 k8s 的 readless probe 之类的帮忙发请求

liuzhaowei55

2021-01-06 11:38:55 +08:00 via Android

这个问题也困扰已久，但没有找到好的解决方案，懒加载，random 设置都尝试过了，隔一段时间没有请求，重新请求就会响应很慢，估计开个定时器不断请求可破这个问题了。

young1lin

2021-01-06 11:39:00 +08:00

这是 Spring MVC 的问题好吗，根本不是 Spring Boot 的问题，虽然后者把前者整合进来了。这个是第一次 DispatcherServlet 初始化时，把那些 HandleMapping 加载进来所以慢。你要想不慢，自己加个 Spring Boot 初始化类，主动触发一下，它不 ok 吗？

otakustay

2021-01-06 12:22:15 +08:00

没事的再几年你们拥抱云原生了用 FAAS 会觉得这问题更酸爽的，提前适应适应

shayang888

2021-01-06 12:30:52 +08:00

@chendy
@liuzhaowei55 明白了谢谢了

hantsy

2021-01-06 15:19:34 +08:00

有几人看过官方 Spring Boot 参考文档或者博客： https://spring.io/blog/2019/03/14/lazy-initialization-in-spring-boot-2-2

By default, when an application context is being refreshed, every bean in the context is created and its dependencies are injected. By contrast, when a bean definition is configured to be initialized lazily it will not be created and its dependencies will not be injected until it’s needed.
。。。

In a web application lazy initialization can lead to increased latency for HTTP requests that trigger bean initialization. This will typically just be the first request but it may have an adverse effect on load-balancing and auto-scaling.

hantsy

2021-01-06 15:23:11 +08:00

1，关掉 lazy initialization

2，或者你可以自己写一个 java/main 去启动你的 Application，完全自己控制 Bean Registration，不需要 Spring Boot 。https://github.com/hantsy/spring-reactive-sample/blob/master/register-bean/src/main/java/com/example/demo/Application.java#L17，

chendy

2021-01-06 15:42:41 +08:00

@hantsy 然而这个问题并不是懒加载导致的……更何况早年 spring-boot 压根没有懒加载

340244120w

2021-01-06 16:38:05 +08:00

@hantsy #10 懒加载默认开启是 spring2.2 才引入的，之前默认关闭的
https://spring.io/blog/2018/12/12/how-fast-is-spring

340244120w

2021-01-06 16:41:25 +08:00

说错了，只是加了个全局 bean 懒加载的设置

zliea

2021-01-06 16:49:08 +08:00

我想健康检查是不是能解决这个问题？

IMCA1024

2021-01-06 16:50:13 +08:00

@ztechstack 貌似是的

chendy

2021-01-06 16:53:10 +08:00

@ztechstack 是的，健康检查帮忙预热接口…

sampeng

2021-01-06 16:58:52 +08:00

@IMCA1024
@chendy
@ztechstack

健康检查是歪路子。谁健康检查去健康检查业务接口？况且有几百个接口的时候怎么搞？

hantsy

2021-01-06 17:52:29 +08:00

懒加载？ Lazy Loading ？不知道你们说什么东西了。

chendy

2021-01-06 17:58:46 +08:00

@sampeng 随便什么接口，吃一个请求，接受请求这一层就预热起来了，业务的缓存啥的管不着也不是这个问题

hantsy

2021-01-06 18:27:57 +08:00

我实在搞不懂，你们在纠结什么？从我的角度没有一点意义的事情。

试了一下我的现在的项目。https://github.com/hantsy/spring-r2dbc-sample/tree/master/database-client

前面是启动后首次请求。两次请求，没看出来有多大差别。

C:\Users\hantsy>curl http://localhost:8080/posts -v --trace-time
18:22:06.375000 * Trying ::1...
18:22:06.375000 * TCP_NODELAY set
18:22:06.578000 * Trying 127.0.0.1...
18:22:06.593000 * TCP_NODELAY set
18:22:06.609000 * Connected to localhost (127.0.0.1) port 8080 (#0)
18:22:06.625000 > GET /posts HTTP/1.1
18:22:06.625000 > Host: localhost:8080
18:22:06.625000 > User-Agent: curl/7.55.1
18:22:06.625000 > Accept: */*
18:22:06.625000 >
18:22:06.875000 < HTTP/1.1 200 OK
18:22:06.875000 < transfer-encoding: chunked
18:22:06.890000 < Content-Type: application/json
18:22:06.890000 <
[{"id":"6697b8d0-2113-434a-82bb-20a6c0bb2f37","title":"R2dbc is refined","content":"R2dbc is now part of Spring framework core","metadata":{},"status":"DRAFT","createdAt":"2021-01-06T18:21:56.89318"},{"id":"a320359e-0425-425b-92a0-49bf2345e8a2","title":"my first post","content":"content of my first post","metadata":{"tags":["spring","r2dbc"]},"status":"DRAFT","createdAt":"2021-01-06T18:21:57.56585"}]18:22:06.890000 * Connection #0 to host localhost left intact

C:\Users\hantsy>curl http://localhost:8080/posts -v --trace-time
18:22:55.093000 * Trying ::1...
18:22:55.093000 * TCP_NODELAY set
18:22:55.312000 * Trying 127.0.0.1...
18:22:55.312000 * TCP_NODELAY set
18:22:55.328000 * Connected to localhost (127.0.0.1) port 8080 (#0)
18:22:55.343000 > GET /posts HTTP/1.1
18:22:55.343000 > Host: localhost:8080
18:22:55.343000 > User-Agent: curl/7.55.1
18:22:55.343000 > Accept: */*
18:22:55.343000 >
18:22:55.421000 < HTTP/1.1 200 OK
18:22:55.421000 < transfer-encoding: chunked
18:22:55.421000 < Content-Type: application/json
18:22:55.437000 <
[{"id":"6697b8d0-2113-434a-82bb-20a6c0bb2f37","title":"R2dbc is refined","content":"R2dbc is now part of Spring framework core","metadata":{},"status":"DRAFT","createdAt":"2021-01-06T18:21:56.89318"},{"id":"a320359e-0425-425b-92a0-49bf2345e8a2","title":"my first post","content":"content of my first post","metadata":{"tags":["spring","r2dbc"]},"status":"DRAFT","createdAt":"2021-01-06T18:21:57.56585"}]18:22:55.437000 * Connection #0 to host localhost left intact

C:\Users\hantsy>

hantsy

2021-01-06 18:29:36 +08:00

上面这人是 Spring WebFlux 程序，没用 Spring Boot 。

hantsy

2021-01-06 19:32:34 +08:00

Spring MVC 程序。https://github.com/hantsy/spring-playground/tree/master/programming-models/webmvc-fn

本地测试如下：

C:\Users\hantsy>curl http://localhost:8080/ -v --trace-time
19:23:51.593000 * Trying ::1...
19:23:51.593000 * TCP_NODELAY set
19:23:51.593000 * Connected to localhost (::1) port 8080 (#0)
19:23:51.625000 > GET / HTTP/1.1
19:23:51.625000 > Host: localhost:8080
19:23:51.625000 > User-Agent: curl/7.55.1
19:23:51.625000 > Accept: */*
19:23:51.625000 >
19:23:51.671000 < HTTP/1.1 200
19:23:51.671000 < Content-Type: application/json
19:23:51.671000 < Transfer-Encoding: chunked
19:23:51.671000 < Date: Wed, 06 Jan 2021 11:23:51 GMT
19:23:51.671000 <
[{"id":7,"title":"Hello Spring","content":"This is my first post of Spring","createdAt":"2021-01-06T19:23:00.37556"},{"id":8,"title":"Hello Again","content":"The second post","createdAt":"2021-01-06T19:23:00.37556"}]19:23:51.687000 * Connection #0 to host localhost left intact

C:\Users\hantsy>curl http://localhost:8080/ -v --trace-time
19:23:55.656000 * Trying ::1...
19:23:55.656000 * TCP_NODELAY set
19:23:55.656000 * Connected to localhost (::1) port 8080 (#0)
19:23:55.703000 > GET / HTTP/1.1
19:23:55.703000 > Host: localhost:8080
19:23:55.703000 > User-Agent: curl/7.55.1
19:23:55.703000 > Accept: */*
19:23:55.703000 >
19:23:55.718000 < HTTP/1.1 200
19:23:55.718000 < Content-Type: application/json
19:23:55.734000 < Transfer-Encoding: chunked
19:23:55.734000 < Date: Wed, 06 Jan 2021 11:23:55 GMT
19:23:55.734000 <
[{"id":7,"title":"Hello Spring","content":"This is my first post of Spring","createdAt":"2021-01-06T19:23:00.37556"},{"id":8,"title":"Hello Again","content":"The second post","createdAt":"2021-01-06T19:23:00.37556"}]19:23:55.734000 * Connection #0 to host localhost left intact

hantsy

2021-01-06 19:36:10 +08:00

上面的用 PostMan, Chrome 不知道对浏览器缓存有没有研究，是不是每次请求前都是事先删除了本地缓存。

zliea

2021-01-06 22:26:23 +08:00

@sampeng 健康检查，检查一下各种数据库，然后同时预热。虽然有点歪门邪道，但可以考虑用 k8s 就绪健康检查做完整的健康检查。

hantsy

2021-01-07 11:42:26 +08:00

@ztechstack 完全看不懂这是什么骚操作？用来作什么？对你的程序有什么用？你的程序每次请求完了要重新启动吗？第一次请求延迟如果考虑一个长期运行的程序，比如程序运行了 100 天没重启，它解决了什么问题。

hantsy

2021-01-07 11:52:58 +08:00

@340244120w spring.main.lazy-initialization 这是全局延迟初始化，从来不知道被称为 [懒加载] （这是我第一次听说）。一般情况下，如果你是传统的三层结构，启用的话，repository, controller 等都不会事先初始化。这个在你的程序达到百个 Bean 的延迟是很明显的，我深有体会。

但是像楼主那样两次请求可以相差一个数据量级的，我从来没见过（包含我用其它语言写过的 Restful API ）。一般我的程序可能使用缓存等，加上后面请求可能受系统和网络资源限制不一样，一般有 2-3 倍差别我觉得还是比较正常。

hantsy

2021-01-07 11:54:21 +08:00

@chendy
@340244120w 帮我看一下我的程序哪里出了问题，为什么重现不了 10 倍的场景。

340244120w

2021-01-07 13:21:23 +08:00

@hantsy
我试了下，配置文件加上 logging.level.web=trace 后前后两次打印
第一次请求--------------------------------------------
2021-01-07 13:13:52.659 INFO 43592 --- [nio-8080-exec-2] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring DispatcherServlet 'dispatcherServlet'
2021-01-07 13:13:52.659 INFO 43592 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : Initializing Servlet 'dispatcherServlet'
2021-01-07 13:13:52.659 TRACE 43592 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : Detected org.springframework.web.multipart.support.StandardServletMultipartResolver@49277b55
2021-01-07 13:13:52.659 TRACE 43592 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : Detected org.springframework.web.servlet.i18n.AcceptHeaderLocaleResolver@18bda305
2021-01-07 13:13:52.659 TRACE 43592 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : Detected org.springframework.web.servlet.theme.FixedThemeResolver@71e0316e
2021-01-07 13:13:52.660 TRACE 43592 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : Detected DefaultRequestToViewNameTranslator
2021-01-07 13:13:52.660 TRACE 43592 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : Detected SessionFlashMapManager
2021-01-07 13:13:52.660 DEBUG 43592 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : enableLoggingRequestDetails='false': request parameters and headers will be masked to prevent unsafe logging of potentially sensitive data
2021-01-07 13:13:52.660 INFO 43592 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : Completed initialization in 1 ms
2021-01-07 13:13:52.667 TRACE 43592 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : GET "/", parameters={}, headers={masked} in DispatcherServlet 'dispatcherServlet'
2021-01-07 13:13:52.669 TRACE 43592 --- [nio-8080-exec-2] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to com.example.demo.DemoApplication$PostController#getAll()
2021-01-07 13:13:52.675 TRACE 43592 --- [nio-8080-exec-2] o.s.web.method.HandlerMethod : Arguments: []
2021-01-07 13:13:52.691 DEBUG 43592 --- [nio-8080-exec-2] m.m.a.RequestResponseBodyMethodProcessor : Using 'text/plain', given [*/*] and supported [text/plain, */*, text/plain, */*, application/json, application/*+json, application/json, application/*+json]
2021-01-07 13:13:52.692 TRACE 43592 --- [nio-8080-exec-2] m.m.a.RequestResponseBodyMethodProcessor : Writing ["1111"]
2021-01-07 13:13:52.699 TRACE 43592 --- [nio-8080-exec-2] s.w.s.m.m.a.RequestMappingHandlerAdapter : Applying default cacheSeconds=-1
2021-01-07 13:13:52.699 TRACE 43592 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : No view rendering, null ModelAndView returned.
2021-01-07 13:13:52.699 DEBUG 43592 --- [nio-8080-exec-2] o.s.web.servlet.DispatcherServlet : Completed 200 OK, headers={masked}

第二次请求---------------------------------------------------

2021-01-07 12:58:11.230 TRACE 43278 --- [nio-8080-exec-3] o.s.web.servlet.DispatcherServlet : GET "/2", parameters={}, headers={masked} in DispatcherServlet 'dispatcherServlet'
2021-01-07 12:58:11.230 TRACE 43278 --- [nio-8080-exec-3] s.w.s.m.m.a.RequestMappingHandlerMapping : Mapped to com.example.demo.DemoApplication$PostController#getById()
2021-01-07 12:58:11.230 TRACE 43278 --- [nio-8080-exec-3] .w.s.m.m.a.ServletInvocableHandlerMethod : Arguments: []
2021-01-07 12:58:11.231 DEBUG 43278 --- [nio-8080-exec-3] m.m.a.RequestResponseBodyMethodProcessor : Using 'text/plain', given [*/*] and supported [text/plain, */*, text/plain, */*, application/json, application/*+json, application/json, application/*+json]
2021-01-07 12:58:11.231 TRACE 43278 --- [nio-8080-exec-3] m.m.a.RequestResponseBodyMethodProcessor : Writing ["2222"]
2021-01-07 12:58:11.231 TRACE 43278 --- [nio-8080-exec-3] o.s.web.servlet.DispatcherServlet : No view rendering, null ModelAndView returned.
2021-01-07 12:58:11.231 DEBUG 43278 --- [nio-8080-exec-3] o.s.web.servlet.DispatcherServlet : Completed 200 OK, headers={masked}

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

我这个不带数据库的纯 springmvc 简单项目，dispatcher 初始化其实就 1ms 。
第一次请求 spring 内部耗时是 699-667=32ms （快点的时候十多 ms ），不过算上 jvm 预热其实也正常。
整体 100ms 以上的话，得加上 spring.main.lazy-initialization=true 才行。

340244120w

2021-01-07 13:29:08 +08:00

而且 springmvc 性能本来的确就不咋滴。。基本操作

chendy

2021-01-07 13:41:12 +08:00

@hantsy 啊这，我们都不纠结了只有你还在纠结啊
你的例子第一次是比第二次慢，不就符合楼主的描述了么，至于 10 倍……我 ctrl f 在帖子里没搜到 10 倍，难道 block 了说慢十倍的人？……
楼主说的这种情况和 spring 的 bean 初始化时机没关系，只能说和 jvm 预热有关（可能还有数据库连接池预热，程序内缓存预热吧啦吧啦
随手做了几个测试，浏览器里访问，反复刷新，容易观察
1. 随手找了一个应用（ SpringMVC ）加个空接口，首次 98ms，后续 4~8ms
2. start.spring.io 做了个只有 webflux 依赖的空项目，加个空接口，首次 100ms，后续 4~8ms
3. netty http server，不做任何处理只返回空内容，首次 80ms，后续 1-5ms
4. 直接 java.net.ServerSocket 假装是个 http server，不做任何处理只返回空内容，首次和后续都是 12-18ms
可以发现除了最最最简单的写法之外其他几个都存在首次比后续慢的情况，应该就是 jvm 预热的问题

hantsy

2021-01-07 13:50:22 +08:00

@chendy 翻了一下。还不止呢，原描述是 150MS->5ms 太夸张了。

你这么大的发现，快去申请专利。谁整天写个 Hello World 玩，对于 Web 程序，数据库操作才是最大瓶颈。

zliea

2021-01-08 02:11:58 +08:00

@hantsy k8s 健康检查分为两种：就绪检查与存活检查。
1. 就绪的健康检查是 pod （程序）启动时，检查服务是否可以正常接受 HTTP 请求，如果检查正常之后才会将 HTTP 流量转发的这个 pod （程序），失败则重启 pod （程序）；
2. 存活的健康检查是 pod （程序）运行时，如果检查失败，则将 pod （服务） kill 掉，重新启动一个 pod （服务）。

现在 springboot 的问题不就是第一次请求的时候慢，但这个第一次请求是在就绪的健康检查的时候（此时程序没有接受业务上的 http 请求）就给预热完毕了，那么其他的任何接口请求时间正常了。

k8s 两种检查的好处在于：
1. 就绪的检查可以实现一些稍稍比较重的任务，比如数据库连接状态或者数据是否成功初始化的检查，因为只是在启动时请求，不会因为检查而影响效率；
2. 存活检查就可以很简单，一般单纯返回程序运行状态或加上数据库连接状态就可以了。

实际在使用 k8s 之前，nginx 上一般都会在 upstream 配置一个统一的健康检查，只不过这个没有区分两种检查，同样也是进行了预热。