V2EX = way to explore
V2EX 是一个关于分享和探索的地方
现在注册
已注册用户请  登录
goodboy95
V2EX  ›  Java

求解答一个 Java 运行速度的问题

  •  1
     
  •   goodboy95 · 2020-03-26 15:32:28 +08:00 · 3044 次点击
    这是一个创建于 1737 天前的主题,其中的信息可能已经有所发展或是发生改变。

    下面的 java 程序,在我的电脑上运行时间 600ms 左右,但把 for 循环里面注释掉的两行加回来的话,时间反而会降到 50-60ms,有人明白这是什么情况吗? java 版本是 JDK11,windows ( win10 )和 linux ( ubuntu 18.04 )均有这种情况。

    顺便问一下,spring 是自身做了缓存吗,我把这段代码和一个依赖外部参数的 sql 查询代码放在 spring boot 项目的一个接口里面,每次调用都修改参数的话,只有前两次会耗比较长时间,后面基本就不耗时间了……

    public static void main(String[] args) {
        long t1 = new Date().getTime();
        int res = 0;
        int n = 0;
        for (int i = 0; i < 2000000000; i++) {
            // int baseNum = 6;
            // n = baseNum * 1346;
            res |= n;
        }
        long t2 = new Date().getTime();
        System.out.println(String.format("time: %d, res: %d", t2 - t1, res));
    }
    
    17 条回复    2020-03-30 18:34:07 +08:00
    ak47007
        1
    ak47007  
       2020-03-26 15:36:33 +08:00
    我有两个疑问?
    ak47007
        2
    ak47007  
       2020-03-26 15:37:28 +08:00
    1. 为什么不用 System.currentTimeMillis()
    2. 为什么不将 int baseNum=6; 写在外面?
    drquack
        3
    drquack  
       2020-03-26 15:53:45 +08:00   ❤️ 1
    我对 Java 不熟,但是这个应该和循环优化有关,加注释之前 n 和 baseNum 的作用域都在 for 循环以内,所以可能就被循环就被优化掉了。

    如果你改一下加注释后的代码,把 `int n = 0` 放到循环里面,速度会比加注释之前更快。
    goodboy95
        4
    goodboy95  
    OP
       2020-03-26 15:55:00 +08:00
    @ak47007 我 java 也是刚学几天,currentTimeMillis 这个之前真不知道……
    之前看网上有人讨论 java 乘法和位运算的速度的时候,就随手写了这段代码。最开始的时候我写的 n = baseNum * 1024,至于 int baseNum = 6;那一行本来我是想之后改成 int baseNum = i 的,先写个常数试试,结果试完之后发现了现在这个奇怪的情况。
    不过 int baseNum = 6;写到外面之后,for 循环里面不管有没有注释都是 600ms 了,难道是因为现在这个代码去掉注释就会把 n 的数值做成常量?
    drquack
        5
    drquack  
       2020-03-26 15:56:28 +08:00
    (想起了写编译器的时候各种循环优化的骚操作
    goodboy95
        6
    goodboy95  
    OP
       2020-03-26 16:26:57 +08:00
    话说回来,把注释掉的代码加进去,去掉 Date 相关代码和 println 之后,用 javap -c 查看的时候,结果是这样的:
    ```
    public static void main(java.lang.String[]);
    Code:
    0: iconst_0
    1: istore_1
    2: iconst_0
    3: istore_2
    4: iconst_0
    5: istore_3
    6: iload_3
    7: ldc #2 // int 2000000000
    9: if_icmpge 33
    12: bipush 6
    14: istore 4
    16: iload 4
    18: sipush 1346
    21: imul
    22: istore_2
    23: iload_1
    24: iload_2
    25: ior
    26: istore_1
    27: iinc 3, 1
    30: goto 6
    33: return
    ```
    里面把 for 循环完完整整的写了一遍……JVM 的优化也太厉害了点吧……
    luckyrayyy
        7
    luckyrayyy  
       2020-03-26 16:28:21 +08:00
    很有意思的一个问题,我对代码进行了删减,基本可以确定和那两行注释没关系,和 res |= n 这个具体操作换成+=之类的运算也是有很大差距。基本可以确定在循环外创建变量并且赋值导致的。我再研究下具体怎么回事
    luckyrayyy
        8
    luckyrayyy  
       2020-03-26 16:43:30 +08:00   ❤️ 2
    找打了 R 大知乎的一个回答,试了试果然如此
    https://www.zhihu.com/question/58735131
    OysterQAQ
        9
    OysterQAQ  
       2020-03-26 17:11:07 +08:00
    问题在于 n 的赋值吧
    goodboy95
        10
    goodboy95  
    OP
       2020-03-26 17:17:20 +08:00
    @OysterQAQ 把 n 写成 final 之后,速度确实快了(虽然字节码上看不出什么区别……)
    上面也有人提到 JIT 在里面搞事,我也在看。
    OysterQAQ
        11
    OysterQAQ  
       2020-03-26 17:31:46 +08:00
    long t1 =System.currentTimeMillis();
    int res = 0;
    int n = 0;

    for (int i = 0; i < 2000000000; i++) {
    n = 6 * 1346;
    res |= n;
    }
    long t2 =System.currentTimeMillis();
    System.out.println(String.format("time: %d, res: %d", t2 - t1, res));
    问题只在于 n = 6 * 1346;
    OysterQAQ
        12
    OysterQAQ  
       2020-03-26 20:19:02 +08:00   ❤️ 1
    OysterQAQ
        13
    OysterQAQ  
       2020-03-26 20:19:53 +08:00
    具体可以看楼上 差别就是循环内赋值的话多两条指令 多两条 80ms 少两条 600ms 感觉和 cpu 缓存有关了
    secondwtq
        14
    secondwtq  
       2020-03-27 04:51:50 +08:00   ❤️ 1
    拿 11 楼的例子粗略看了一下

    36 ms 的汇编:
    0x00007f6130116540: mov r9d,r13d ;*goto
    ; - Benchmark::doTest@30 (line 8)

    0x00007f6130116543: or ebx,0x7b ;*ior ; - Benchmark::doTest@25 (line 10)

    0x00007f6130116546: mov r13d,r9d
    0x00007f6130116549: add r13d,0x10 ;*iinc
    ; - Benchmark::doTest@27 (line 8)

    0x00007f613011654d: cmp r13d,0x773593f1
    0x00007f6130116554: jl 0x00007f6130116540 ;*if_icmpge
    ; - Benchmark::doTest@17 (line 8)

    531 ms 的汇编:
    0x00007f5b8d070650: mov r9d,r13d ;*goto
    ; - Benchmark::doTest@27 (line 8)

    0x00007f5b8d070653: or r14d,ebx
    0x00007f5b8d070656: or r14d,ebx
    0x00007f5b8d070659: or r14d,ebx
    0x00007f5b8d07065c: or r14d,ebx
    0x00007f5b8d07065f: or r14d,ebx
    0x00007f5b8d070662: or r14d,ebx
    0x00007f5b8d070665: or r14d,ebx
    0x00007f5b8d070668: or r14d,ebx
    0x00007f5b8d07066b: or r14d,ebx
    0x00007f5b8d07066e: or r14d,ebx
    0x00007f5b8d070671: or r14d,ebx
    0x00007f5b8d070674: or r14d,ebx
    0x00007f5b8d070677: or r14d,ebx
    0x00007f5b8d07067a: or r14d,ebx
    0x00007f5b8d07067d: or r14d,ebx
    0x00007f5b8d070680: or r14d,ebx ;*ior ; - Benchmark::doTest@22 (line 10)

    0x00007f5b8d070683: mov r13d,r9d
    0x00007f5b8d070686: add r13d,0x10 ;*iinc
    ; - Benchmark::doTest@24 (line 8)

    0x00007f5b8d07068a: cmp r13d,0x773593f1
    0x00007f5b8d070691: jl 0x00007f5b8d070650 ;*if_icmpge

    可见两边都做了 16 次的 unroll,两边的时间基本也是差 16 倍左右
    但是大概这里编译器并不知道 outer scope 的变量具体是什么值,所以如果不在循环内赋值,就会强行做 16 次 or
    感觉这个优化还没开全 ... 这 16 次 or 换成一次是一样的
    当然全都优化之后是个常数,就量不出时间了
    warcraft1236
        15
    warcraft1236  
       2020-03-27 11:07:10 +08:00
    想知道 |= 这个是啥意思?
    goodboy95
        16
    goodboy95  
    OP
       2020-03-27 15:46:40 +08:00
    @warcraft1236 按位取或,写这个的原因纯粹是让循环对外干点事情,防止 java 把 for 循环优化掉。
    yjxjn
        17
    yjxjn  
       2020-03-30 18:34:07 +08:00
    兄弟,我试了一下,macOS 10.14 Eclipse JDK1.8 注释不注释 都是 500ms 左右
    关于   ·   帮助文档   ·   博客   ·   API   ·   FAQ   ·   实用小工具   ·   2038 人在线   最高记录 6679   ·     Select Language
    创意工作者们的社区
    World is powered by solitude
    VERSION: 3.9.8.5 · 26ms · UTC 00:32 · PVG 08:32 · LAX 16:32 · JFK 19:32
    Developed with CodeLauncher
    ♥ Do have faith in what you're doing.