• 请不要在回答技术问题时复制粘贴 AI 生成的内容
samples
V2EX  ›  程序员

javaweb 请求一个接口,第一次请求特别慢在 20-40s,随后请求正常,这是什么问题?

  •  
  •   samples · Aug 5, 2019 · 8452 views
    This topic created in 2647 days ago, the information mentioned may be changed or developed.

    问题详情:请求一个接口,在服务器上第一次请求特别慢在 20-40s,随后请求正常。本地测都是正常的,无论是不是第一请求,都可以在 2s 内响应。

    下面贴出测出的一些数据

    1.两个 service 都有事务,但应该与事务无关,去除事务后耗时是一样的 2.“保存耗时” 在 20-40s,其他耗时基本在 200ms 以内 3.环境:springboot spring-data-jpa

    applyService

        @Override
        public Apply save(LawCase lawCase) {
            long l = System.currentTimeMillis();
            LawCase law = lawCaseService.save(lawCase);
            long l1 = System.currentTimeMillis();
            System.out.println("保存耗时" + (l1 - l));
            Apply apply = new Apply();
            // set 一些属性值
            applyRepository.save(apply);
            long l2 = System.currentTimeMillis();
            System.out.println("保存记录耗时" + (l2 - l1));
            return apply;
        }
    

    lawCaseService

        @Override
        public LawCase save(LawCase lawCase) {
            // 处理关系和初始化标题顺序不可颠倒
            long l = System.currentTimeMillis();
            handleRelation(lawCase);
            long l1 = System.currentTimeMillis();
            initTitle(lawCase);
            long l2 = System.currentTimeMillis();
            lawCaseRepository.save(lawCase);
            long l3 = System.currentTimeMillis();
            System.out.println("处理关系" + (l1 - l));
            System.out.println("初始化标题" + (l2 - l1));
            System.out.println("保存 db" + (l3 - l2));
            return lawCase;
        }
    
    Supplement 1  ·  Aug 5, 2019
    嗯嗯,问题找到了是哪里了。谢谢大家。具体的原因我再分析。

    出问题的是 IdUtil.simpleUUID(); 这个方法。这个是 hutool 库的方法。

    我记得这个库有重写了 jdk 的 UUID,生成 uuid 会更快。

    所以我是没有想到会是它的,都没有给这个方法打 bug 测下耗时。

    具体这个方法为啥会耗时这么长时间,后续我再分析。
    36 replies  •  2019-08-07 09:06:12 +08:00
    wlfeng
    wlfeng
    Aug 5, 2019
    1
    是不是第一次请求初始化加载太多数据了
    samples
    samples
    OP
    Aug 5, 2019
    2
    @wlfeng 如果是这个原因那么本地和服务器应该是一样的,但是本地第一次请求是正常的
    micean
    micean
    Aug 5, 2019
    3
    第一次应该就是连接数据库慢吧?
    有些云服务在第一次连接自建数据库的时候特别慢
    samples
    samples
    OP
    Aug 5, 2019
    4
    老哥们给个排查的方向
    samples
    samples
    OP
    Aug 5, 2019
    5
    @micean 本地和服务器上 连接的是同一个数据库
    Raymon111111
    Raymon111111
    Aug 5, 2019
    6
    测试建立数据库连接是不是问题

    把数据库访问都去掉试试
    gz911122
    gz911122
    Aug 5, 2019
    7
    是不是用到 session 了
    或者用到随机数了?

    服务器环境噪音比较小,随机数生成第一时间会比较场
    Aresxue
    Aresxue
    Aug 5, 2019
    8
    远程 debug 一下,看下是哪里慢
    cheng6563
    cheng6563
    Aug 5, 2019 via iPhone
    9
    随机数问题吧
    启动命令里加 -Djava.security.egd=file:/dev/./urandom
    试试看
    BBCCBB
    BBCCBB
    Aug 5, 2019
    10
    第一次访问有些初始化工作要做,比如初始化数据库连接池等...
    Caballarii
    Caballarii
    Aug 5, 2019
    11
    jdk 问题,9L 正解,LS 们不要乱猜了
    micean
    micean
    Aug 5, 2019
    12
    @samples 跟数据库没关系,我以前遇到过,应用放数据库服务器一点问题都没有,跨服务器几分钟都没响应,后来联系服务商,不知道他们怎么解决的
    qqpkat2
    qqpkat2
    Aug 5, 2019
    13
    9 11 楼都不对,尤其是 11 楼瞎几把乱说
    随机数问题是导致 tomcat 启动非常慢的原因而不是楼主说的第一次慢
    wysnylc
    wysnylc
    Aug 5, 2019❤️1
    14
    熵池初始化问题
    hosaos
    hosaos
    Aug 5, 2019
    15
    你不都打了耗时日志了么,哪一步慢呢?
    Caballarii
    Caballarii
    Aug 5, 2019
    16
    @qqpkat2 LZ 用的 springboot,java -jar 启动,随机数导致第一次访问慢有什么问题?我这么说是因为我就碰到过,并且这样解决了。动不动说别人瞎几把乱说是不是脑子里有屎?
    wangxiaoaer
    wangxiaoaer
    Aug 5, 2019 via Android
    17
    预热?

    休眠?
    hellwys1
    hellwys1
    Aug 5, 2019
    18
    mark,遇到相同的问题,也是 save 时出现耗时过多的问题
    jorneyr
    jorneyr
    Aug 5, 2019
    19
    我们这也会遇到第一次访问慢的情况,不过在 5s 左右,我们这的原因是第一次连接 MySQL 和 MongoDB 导致的,接下来就好了。
    lff0305
    lff0305
    Aug 5, 2019
    20
    遇到过 9 楼的问题,排查到最后,是因为
    1. 测试环境是 VMware Esxi 虚拟机;
    2. 第一次访问,系统初始化数据库连接池,连接池初始化 JDBC 驱动,ORACLE jdbc 驱动在连接的初始化时要生成 SecureRandom 做秘钥。
    3. 在那个 Esxi 环境,生成 SecureRadom 极其缓慢。因为缺少某些“硬件操作信息”来生成真随机数

    同样的凡是使用了 SecureRandom 的所有类库( https/ssl,rsa 等等等)都有类似的问题。
    这个问题在物理机上无法重现。

    修改:按照 9 楼的方法修改 jvm 启动参数,即用基数种子的数学伪随机数来替换基于硬件操作信息的真随机数
    RRL
    RRL
    Aug 5, 2019
    21
    9 和 11 可能性不大,这种场景还是不要乱猜,用 Arthas 去 Trace Watch 一下就很清晰了。

    https://github.com/alibaba/arthas

    https://alibaba.github.io/arthas/
    lff0305
    lff0305
    Aug 5, 2019
    22
    @lff0305 忘说了直接用 JProfile 跟踪下就知道了,或者在卡的时候 jstack 下就知道卡在哪里了,我们当时是反复执行 jstack,发现 n 个线程都 block 在初始化数据库连接池 - 初始化 jdbc - 初始化 Oracle 连接 - 生成 SecureRandom 那里
    samples
    samples
    OP
    Aug 5, 2019
    23
    @Raymon111111
    @gz911122
    @Aresxue
    @cheng6563
    @BBCCBB
    @Caballarii
    @micean
    @qqpkat2
    @wysnylc
    @hosaos
    @Caballarii
    @wangxiaoaer
    @hellwys1
    @jorneyr
    @lff0305
    @blackboom
    谢谢老哥们。找到问题了,确实是生成 uuid 的方法出了问题。这个是 hutool 库的一个生成 id 的方法。至于具体原因我再分析下。
    opengps
    opengps
    Aug 5, 2019 via Android
    24
    服务器是虚拟机的话,硬盘必然比本地慢一拍
    再说首次访问确实需要很多组件都从硬盘添加到内存
    lawler
    lawler
    Aug 5, 2019
    25
    移除 hutool 吧。这个库问题真的很多,之前拦截全局 cookies。会导致所有 http 相关的类受影响。
    msg7086
    msg7086
    Aug 5, 2019
    26
    可以装个虚拟随机数生成器试试。Debian 下有个 haveged 可以用,特别适合虚拟机。
    nicoljiang
    nicoljiang
    Aug 5, 2019
    27
    一般是云服务器的「熵」不足。
    Java 需要调整一下生成随机数的方式。
    samples
    samples
    OP
    Aug 5, 2019
    28
    @lawler 嗯嗯有这个打算
    auin
    auin
    Aug 5, 2019
    29
    久闻 hutool 大名,就是一直没用过,楼主查出问题了能否 @ 我一下,让我继续放弃使用这个库
    qqpkat2
    qqpkat2
    Aug 5, 2019
    30
    @Caballarii 你连别人问题都没看清楚就来回复,认真审题好么
    什么叫第一次调用接口,那是系统已经起来了去调用
    lolizeppelin
    lolizeppelin
    Aug 5, 2019
    31
    看样子像是 linux 随机不够?
    如果是的话, 有个命令能刷新这玩意的
    srx1982
    srx1982
    Aug 5, 2019 via Android
    32
    @nicoljiang 非常有可能
    nickchenyx
    nickchenyx
    Aug 5, 2019
    33
    @liuxey 这和 Hutool 又没关系,问题在于 JDK 自身的随机数生成问题,你这个赖到 Hutool 上不道义
    CEBBCAT
    CEBBCAT
    Aug 5, 2019
    34
    随机数产生器这么热手的么……
    auin
    auin
    Aug 5, 2019
    35
    @nickchenyx 没仔细看,抱歉了
    samples
    samples
    OP
    Aug 7, 2019
    36
    @nickchenyx 这个怎么说呢,hutool 调用的也是 jdk 的 SecureRandom,jdk 的 UUID 也是用的 SecureRandom,但不知为何 hutool 的第一次调用就需要非常长的时间,难道它把一些随机数加再到内存了?
    About   ·   Help   ·   Advertise   ·   Blog   ·   API   ·   FAQ   ·   Privacy   ·   Solana   ·   5510 Online   Highest 6679   ·     Select Language
    创意工作者们的社区
    World is powered by solitude
    VERSION: 3.9.8.5 · 90ms · UTC 02:02 · PVG 10:02 · LAX 18:02 · JFK 21:02
    ♥ Do have faith in what you're doing.