V2EX = way to explore
V2EX 是一个关于分享和探索的地方
现在注册
已注册用户请  登录
V2EX 提问指南
esolve
V2EX  ›  问与答

spring-boot web 项目启动后,线程中有异步操作的话,第一次 HTTP 请求会超时很久是怎么回事?

  •  
  •   esolve · 2017-10-12 18:18:04 +08:00 · 4906 次点击
    这是一个创建于 2599 天前的主题,其中的信息可能已经有所发展或是发生改变。

    大致上的代码结构是

    @RestController
    class ApiClass{
    
        Logger logger = LoggerFactory.getLogger("log");
        
        @Autowired
        ApiService apiService;
        
        @RequestMapping(value = "/api")
        public String doApi{
            logger.info("HTTP 请求  ");
            String result = apiService.doService();
            return ResponseUtil.jsonSuccess(result); //这里产生类似下面日志中的 json 串
        }
         
    }
    
    @Service
    class ApiService{
        
        @Transactional
        String doService(){
            logger.debug("测试 1 处");
            。。。
            logger.debug("测试 2 处");
            LocalThread.FIXED_THREAD_POOL.execute(new Runnable() {
                    @Override
                    public void run() {
                        doAsync();  //大量数据库操作
                    }
                });
            logger.debug("测试 3 处");
            。。。
            logger.debug("测试 4 处");
            return "xxxx";
            
        }
    
    }
    
    其中
    public class LocalThread {
        public static ExecutorService FIXED_THREAD_POOL = Executors.newFixedThreadPool(5);
    }
    
    2017-10-12 16:24:22,407 INFO  - HTTP 请求  
    2017-10-12 16:26:02,943 DEBUG - 测试 1 处
    2017-10-12 16:26:03,022 DEBUG - 测试 2 处
    2017-10-12 16:26:03,024 DEBUG - 测试 3 处
    2017-10-12 16:26:03,069 DEBUG - 测试 4 处
    
    下面是 spring-boot 日志
    2017-10-12 16:26:03,565 [http-nio-8070-exec-1] DEBUG [org.springframework.web.servlet.mvc.method.annotation.RequestResponseBodyMethodProcessor] - Written [{"code":"2001","message":"成功","body":[{"data":"xxxx"}] as "text/html" using [org.springframework.http.converter.StringHttpMessageConverter@2bdd8394]
    
    但是之后的请求:
    
    2017-10-12 17:28:48,323 INFO  - HTTP 请求
    2017-10-12 17:28:48,324 DEBUG - 测试 1 处
    2017-10-12 17:28:48,330 DEBUG - 测试 2 处
    2017-10-12 17:28:48,330 DEBUG - 测试 3 处
    2017-10-12 17:28:48,332 DEBUG - 测试 4 处
    
    2017-10-12 17:28:48,337 [http-nio-8070-exec-1] DEBUG [org.springframework.web.servlet.mvc.method.annotation.RequestResponseBodyMethodProcessor] - Written [{"code":"2001","message":"成功","body":[{"data":"xxxx"}] as "text/html" using [org.springframework.http.converter.StringHttpMessageConverter@2bdd8394]
    

    其中,我注意到:

    1 第一次请求从 controller 跳转到 service 都花了将近 2 分钟 而之后的请求没这样

    2 第一次请求,从测试 1 到日志打出返回 json,花了将近 0.6 秒,而第二个则是 0.01 秒左右

    为何差别这么大?

    16 条回复    2018-03-30 01:48:42 +08:00
    esolve
        1
    esolve  
    OP
       2017-10-12 19:09:45 +08:00
    用 IDE 在本地运行没这么大延时
    然后发现,pom 里的版本是

    <plugin>
    <groupId>org.apache.maven.plugins</groupId>
    <artifactId>maven-compiler-plugin</artifactId>
    <configuration>
    <source>1.8</source>
    <target>1.8</target>
    <showWarnings>true</showWarnings>
    </configuration>
    </plugin>

    本地环境是 1.8
    但是在部署环境中

    java -version
    java version "1.7.0_55"
    Java(TM) SE Runtime Environment (build 1.7.0_55-b13)
    Java HotSpot(TM) 64-Bit Server VM (build 24.55-b03, mixed mode)

    这个影响这么大吗?
    hpeng
        2
    hpeng  
       2017-10-12 19:30:06 +08:00 via iPhone
    我很怀疑,1.8 的字节码能在 1.7 中跑?我很怀疑你的环境。
    esolve
        3
    esolve  
    OP
       2017-10-12 20:12:31 +08:00 via iPhone
    @hpeng 能跑啊,否则哪来的日志
    WinterWu
        4
    WinterWu  
       2017-10-12 20:21:59 +08:00
    怀疑是初始化,包括数据库相关的。你把日志级别调整到 Trace,看一下整个初始化过程。
    esolve
        5
    esolve  
    OP
       2017-10-12 20:32:41 +08:00
    @WinterWu 那为何在本地 IDE 下跑就没有延迟?
    misaka19000
        6
    misaka19000  
       2017-10-12 20:32:58 +08:00 via Android
    1.7 虚拟机会拒绝运行由 1.8 的编译器生成的字节码的。。
    WinterWu
        7
    WinterWu  
       2017-10-12 20:41:17 +08:00
    1. Spring 使用了大量的延迟加载技术
    2. 你自己去详细跟一下,对比一下差别就知道了,不要什么都问;另外大量问题网上都有现成答案的。
    3. 1.7 的虚拟机当然是不能跑 1.8 的
    mgcnrx11
        8
    mgcnrx11  
       2017-10-12 21:26:26 +08:00 via iPhone
    看看服务器上 hosts 配置,主机名配置是否正确。这些会在第一次影响网络解析
    esolve
        9
    esolve  
    OP
       2017-10-12 21:31:40 +08:00
    @mgcnrx11 这个应该没问题,我对这个 web 项目重启很多次了
    GKLuke
        10
    GKLuke  
       2017-10-12 21:33:48 +08:00 via iPhone
    一般来说,java 生产用什么版本,开发测试就什么版本,精确到小版本
    esolve
        11
    esolve  
    OP
       2017-10-13 11:19:10 +08:00
    @WinterWu

    开了 trace,但是这两分钟的跳跃,中间没有任何信息。。。

    2017-10-13 11:12:49,017 [http-nio-8070-exec-1] DEBUG [org.springframework.jdbc.datasource.DataSourceTransactionManager] - Creating new transaction with name [com.eversec.centertool.modules.woapi.service.WoApiService.getActivityVo]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT,readOnly; ''
    2017-10-13 11:14:29,541 [http-nio-8070-exec-1] DEBUG [org.springframework.jdbc.datasource.DataSourceTransactionManager] - Acquired Connection [ProxyConnection[PooledConnection[com.mysql.jdbc.JDBC4Connection@3440eaa3]]] for JDBC transaction
    esolve
        12
    esolve  
    OP
       2017-10-13 11:20:00 +08:00
    @hpeng 是搞错了,启动脚本里有 source /etc/profile 命令,用的是 1.8
    myz2018
        13
    myz2018  
       2017-10-14 19:01:04 +08:00
    jstack 看一下就知道了额,看看那个线程在做什么,
    jack80342
        14
    jack80342  
       2017-10-26 23:50:35 +08:00
    最近翻译了 Spring Boot 最新的官方文档,欢迎 Fork,https://www.gitbook.com/book/jack80342/spring-boot/details
    zranye
        15
    zranye  
       2018-01-11 09:20:25 +08:00
    @jack80342 朋友,看了你翻译的文档,先表示非常敬佩你的奉献精神。
    提个意见,gitbook 在国内访问实在是太痛苦了,能不能考虑转到国内类似的平台
    jack80342
        16
    jack80342  
       2018-03-30 01:48:42 +08:00
    @zranye #15 哥们,你有推荐的嘛?
    关于   ·   帮助文档   ·   博客   ·   API   ·   FAQ   ·   实用小工具   ·   1834 人在线   最高记录 6679   ·     Select Language
    创意工作者们的社区
    World is powered by solitude
    VERSION: 3.9.8.5 · 24ms · UTC 16:28 · PVG 00:28 · LAX 08:28 · JFK 11:28
    Developed with CodeLauncher
    ♥ Do have faith in what you're doing.