当循环之后有一个`println`时，为什么这个循环多次的程序需要时间？

【问题标题】：Why is this program which loops many times taking time when there is a `println` after the loops?当循环之后有一个`println`时，为什么这个循环多次的程序需要时间？
【发布时间】：2015-07-18 22:43:14
【问题描述】：

这是我正在尝试的小代码。该程序需要大量时间来执行。在运行时，如果我尝试通过 Eclipse 中的终止按钮将其终止，它会返回 Terminate Failed。我可以使用kill -9 <PID> 从终端杀死它。

但是，当我没有在程序的最后一行打印变量结果时（请检查代码的注释部分），程序立即退出。

我想知道：

  1. 为什么在打印结果的值时执行需要时间？
    请注意，如果我不打印 value，同样的循环会立即结束。

  2. 为什么eclipse不能杀死程序？

更新 1： 似乎 JVM 在运行时（而不是在编译时）优化了代码。 This thread 很有帮助。

更新 2： 当我打印value 的值时，jstack <PID> 不起作用。只有jstack -F <PID> 正在工作。有什么可能的原因吗？ 

    public class TestClient {

        private static void loop() {
            long value =0;

            for (int j = 0; j < 50000; j++) {
                for (int i = 0; i < 100000000; i++) {
                    value += 1;
                }
            }
            //When the value is being printed, the program 
            //is taking time to complete
            System.out.println("Done "+ value);

            //When the value is NOT being printed, the program 
            //completes immediately
            //System.out.println("Done ");
        }

        public static void main(String[] args) {
            loop();
        }
    }

【问题讨论】：

  • 这个循环正在运行 5,000,000,000,000 次迭代
  • 最有可能转化您的价值是需要很长时间才能转化为String。
  • 这是因为编译器优化。当您打印结果时，计算和编译将保留循环，另一方面，当您不使用循环中的任何内容时，编译器将删除循环。
  • 我怀疑当您不打印值时编译器会进行一些优化。由于该值未使用，因此不需要运行循环，它会从字节码中删除。让我仔细检查一下这个假设。
  • @Ambrish 我不认为这是编译器级别的优化，如果您使用javap -c TestClient检查两种情况生成的咬代码，两种情况的输出没有区别。跨度>

标签： java eclipse loops println


【解决方案1】：

这是一个 JIT 编译器优化（不是 java 编译器优化）。

如果您比较两个版本的 java 编译器生成的字节码，您会发现两个版本中都存在循环。

这是使用 println 的反编译方法的外观：

private static void loop() {
    long value = 0L;

    for(int j = 0; j < '썐'; ++j) {
        for(int i = 0; i < 100000000; ++i) {
            ++value;
        }
    }

    System.out.println("Done " + value);
}

这是当 println 被删除时反编译的方法的样子：

private static void loop() {
    long value = 0L;

    for(int j = 0; j < '썐'; ++j) {
        for(int i = 0; i < 100000000; ++i) {
            ++value;
        }
    }
}

如您所见，循环仍然存在。

但是，您可以使用以下 JVM 选项启用 JIT 编译器日志记录和程序集打印：

-XX:+UnlockDiagnosticVMOptions -XX:+LogCompilation -XX:+PrintAssembly

您可能还需要下载hsdis-amd64.dylib 并放入您的工作目录（MacOS、HotSpot Java 8）

运行 TestClient 后，您应该会在控制台中看到 JIT 编译器生成的代码。在这里，我将仅发布输出的摘录。

没有 println 的版本：

# {method} 'loop' '()V' in 'test/TestClient'
0x000000010e3c2500: callq  0x000000010dc1c202  ;   {runtime_call}
0x000000010e3c2505: data32 data32 nopw 0x0(%rax,%rax,1)
0x000000010e3c2510: sub    $0x18,%rsp
0x000000010e3c2517: mov    %rbp,0x10(%rsp)
0x000000010e3c251c: mov    %rsi,%rdi
0x000000010e3c251f: movabs $0x10dc760ec,%r10
0x000000010e3c2529: callq  *%r10              ;*iload_3
                                              ; - test.TestClient::loop@12 (line 9)
0x000000010e3c252c: add    $0x10,%rsp
0x000000010e3c2530: pop    %rbp
0x000000010e3c2531: test   %eax,-0x1c18537(%rip)        # 0x000000010c7aa000
                                              ;   {poll_return}
0x000000010e3c2537: retq

带有 println 的版本：

# {method} 'loop' '()V' in 'test/TestClient'
0x00000001092c36c0: callq  0x0000000108c1c202  ;   {runtime_call}
0x00000001092c36c5: data32 data32 nopw 0x0(%rax,%rax,1)
0x00000001092c36d0: mov    %eax,-0x14000(%rsp)
0x00000001092c36d7: push   %rbp
0x00000001092c36d8: sub    $0x10,%rsp
0x00000001092c36dc: mov    0x10(%rsi),%r13
0x00000001092c36e0: mov    0x8(%rsi),%ebp
0x00000001092c36e3: mov    (%rsi),%ebx
0x00000001092c36e5: mov    %rsi,%rdi
0x00000001092c36e8: movabs $0x108c760ec,%r10
0x00000001092c36f2: callq  *%r10
0x00000001092c36f5: jmp    0x00000001092c3740
0x00000001092c36f7: add    $0x1,%r13          ;*iload_3
                                              ; - test.TestClient::loop@12 (line 9)
0x00000001092c36fb: inc    %ebx               ;*iinc
                                              ; - test.TestClient::loop@22 (line 9)
0x00000001092c36fd: cmp    $0x5f5e101,%ebx
0x00000001092c3703: jl     0x00000001092c36f7  ;*if_icmpge
                                              ; - test.TestClient::loop@15 (line 9)
0x00000001092c3705: jmp    0x00000001092c3734
0x00000001092c3707: nopw   0x0(%rax,%rax,1)
0x00000001092c3710: mov    %r13,%r8           ;*iload_3
                                              ; - test.TestClient::loop@12 (line 9)
0x00000001092c3713: mov    %r8,%r13
0x00000001092c3716: add    $0x10,%r13         ;*ladd
                                              ; - test.TestClient::loop@20 (line 10)
0x00000001092c371a: add    $0x10,%ebx         ;*iinc
                                              ; - test.TestClient::loop@22 (line 9)
0x00000001092c371d: cmp    $0x5f5e0f2,%ebx
0x00000001092c3723: jl     0x00000001092c3710  ;*if_icmpge
                                              ; - test.TestClient::loop@15 (line 9)
0x00000001092c3725: add    $0xf,%r8           ;*ladd
                                              ; - test.TestClient::loop@20 (line 10)
0x00000001092c3729: cmp    $0x5f5e101,%ebx
0x00000001092c372f: jl     0x00000001092c36fb
0x00000001092c3731: mov    %r8,%r13           ;*iload_3
                                              ; - test.TestClient::loop@12 (line 9)
0x00000001092c3734: inc    %ebp               ;*iinc
                                              ; - test.TestClient::loop@28 (line 8)
0x00000001092c3736: cmp    $0xc350,%ebp
0x00000001092c373c: jge    0x00000001092c376c  ;*if_icmpge
                                              ; - test.TestClient::loop@7 (line 8)
0x00000001092c373e: xor    %ebx,%ebx
0x00000001092c3740: mov    %ebx,%r11d
0x00000001092c3743: inc    %r11d              ;*iload_3
                                              ; - test.TestClient::loop@12 (line 9)
0x00000001092c3746: mov    %r13,%r8
0x00000001092c3749: add    $0x1,%r8           ;*ladd
                                              ; - test.TestClient::loop@20 (line 10)
0x00000001092c374d: inc    %ebx               ;*iinc
                                              ; - test.TestClient::loop@22 (line 9)
0x00000001092c374f: cmp    %r11d,%ebx
0x00000001092c3752: jge    0x00000001092c3759  ;*if_icmpge
                                              ; - test.TestClient::loop@15 (line 9)
0x00000001092c3754: mov    %r8,%r13
0x00000001092c3757: jmp    0x00000001092c3746
0x00000001092c3759: cmp    $0x5f5e0f2,%ebx
0x00000001092c375f: jl     0x00000001092c3713
0x00000001092c3761: mov    %r13,%r10
0x00000001092c3764: mov    %r8,%r13
0x00000001092c3767: mov    %r10,%r8
0x00000001092c376a: jmp    0x00000001092c3729  ;*if_icmpge
                                              ; - test.TestClient::loop@7 (line 8)
0x00000001092c376c: mov    $0x24,%esi
0x00000001092c3771: mov    %r13,%rbp
0x00000001092c3774: data32 xchg %ax,%ax
0x00000001092c3777: callq  0x0000000109298f20  ; OopMap{off=188}
                                              ;*getstatic out
                                              ; - test.TestClient::loop@34 (line 13)
                                              ;   {runtime_call}
0x00000001092c377c: callq  0x0000000108c1c202  ;*getstatic out
                                              ; - test.TestClient::loop@34 (line 13)
                                              ;   {runtime_call}

您还应该拥有包含 JIT 编译器步骤的热点.log 文件。摘录如下：

<phase name='optimizer' nodes='114' live='77' stamp='0.100'>
            <phase name='idealLoop' nodes='115' live='67' stamp='0.100'>
                <loop_tree>
                    <loop idx='119' >
                        <loop idx='185' main_loop='185' >
                        </loop>
                    </loop>
                </loop_tree>
                <phase_done name='idealLoop' nodes='197' live='111' stamp='0.101'/>
            </phase>
            <phase name='idealLoop' nodes='197' live='111' stamp='0.101'>
                <loop_tree>
                    <loop idx='202' >
                        <loop idx='159' inner_loop='1' pre_loop='131' >
                        </loop>
                        <loop idx='210' inner_loop='1' main_loop='210' >
                        </loop>
                        <loop idx='138' inner_loop='1' post_loop='131' >
                        </loop>
                    </loop>
                </loop_tree>
                <phase_done name='idealLoop' nodes='221' live='113' stamp='0.101'/>
            </phase>
            <phase name='idealLoop' nodes='221' live='113' stamp='0.101'>
                <loop_tree>
                    <loop idx='202' >
                        <loop idx='159' inner_loop='1' pre_loop='131' >
                        </loop>
                        <loop idx='210' inner_loop='1' main_loop='210' >
                        </loop>
                        <loop idx='138' inner_loop='1' post_loop='131' >
                        </loop>
                    </loop>
                </loop_tree>
                <phase_done name='idealLoop' nodes='241' live='63' stamp='0.101'/>
            </phase>
            <phase name='ccp' nodes='241' live='63' stamp='0.101'>
                <phase_done name='ccp' nodes='241' live='63' stamp='0.101'/>
            </phase>
            <phase name='idealLoop' nodes='241' live='63' stamp='0.101'>
                <loop_tree>
                    <loop idx='202' inner_loop='1' >
                    </loop>
                </loop_tree>
                <phase_done name='idealLoop' nodes='253' live='56' stamp='0.101'/>
            </phase>
            <phase name='idealLoop' nodes='253' live='56' stamp='0.101'>
                <phase_done name='idealLoop' nodes='253' live='33' stamp='0.101'/>
            </phase>
            <phase_done name='optimizer' nodes='253' live='33' stamp='0.101'/>
        </phase>

您可以使用JitWatch工具https://github.com/AdoptOpenJDK/jitwatch/wiki进一步分析JIT编译器产生的hotspot.log文件

要禁用 JIT 编译器并以全解释模式运行 Java 虚拟机，您可以使用 -Djava.compiler=NONE JVM 选项。

这个帖子Why is my JVM doing some runtime loop optimization and making my code buggy?也有类似的问题

【讨论】：

【解决方案2】：

这是因为编译器/JVM 优化。当您打印结果时，计算和编译器将保持循环。

另一方面，当您不使用循环中的任何内容时，编译器/JVM 将删除循环。

【讨论】：

  • 其实循环并没有丢在字节码中。所以可能是JVM优化。
  • 不会删除循环。我们在循环value += 1; 中有一些操作。查看字节码。循环仍然存在。
  • 只有在方法中定义了value 变量时才会删除循环。如果变量在方法之外声明，它将始终执行循环。
  • 有什么方法可以验证/找出 JVM 在遇到代码时实际做了什么？
  • 我认为它必须是编译器和JVM的组合。尝试将打印放在catch 的try 中。根据您尝试中的语句，循环有时会被跳过，有时会被执行。认为 JVM 比我们想象的更聪明......
【解决方案3】：

基本上，JVM 真的非常智能。它可以感知您是否使用任何变量，并基于此，它实际上可以删除与该变量相关的任何处理。由于您注释掉了打印“值”的代码行，因此它感觉到该变量不会在任何地方使用，并且不会运行循环，甚至不会运行一次。

但是当您执行打印该值时，它必须运行您的循环，这又是一个非常大的数字 (50000 * 100000000)。现在，这个循环的运行时间取决于你的很多因素，包括但不限于你机器的处理器、分配给 JVM 的内存、处理器的负载等。

就您的 eclipse 无法终止它的问题而言，我可以在我的机器上使用 eclipse 轻松杀死该程序。也许你应该再检查一下。

【讨论】：

  • 其实是JVM优化。
  • 我宁愿将优化未使用的计算称为“公平”。如果它在两种情况下都优化了循环，那将是“聪明的”，因为可以在不循环的情况下计算结果值（你自己暗示过，如何）。
  • @Holger，JVM 最终只是一个程序，它和程序员一样聪明。本质上，如果 JVM 可以通过向前看一个变量不会被使用而省略执行循环，这不是聪明吗？显然，我们可以使用公式 (sum = n * (n + 1)) 来解决 OP 的问题，但是使用这个公式而不是编写循环不是 OP 的聪明之处吗？但是，我知道代码优化不是OP的问题。他只是想了解为什么某事会以特定的方式发生。
  • 关于未使用值的要点是优化器不需要分析循环。它只需要弄清楚调用代码不使用返回值，因此，无论循环做什么或代码是否有循环，都不需要执行代码所有，只要它是无副作用的，这很容易测试 Java 字节码。相反，用乘法替换重复加法确实需要分析循环...
【解决方案4】：

我怀疑当 aou 不打印结果时，编译器会注意到 value 的值从未使用过，因此能够删除整个循环作为优化。

因此，如果没有 println，您根本不会循环，并且程序会在打印您正在执行所有 5,000,000,000,000 次迭代的值时立即退出，这可能会有点冗长。

作为建议尝试

public class TestClient {
public static long loop() {
    long value =0;

    for (int j = 0; j < 50000; j++) {
        for (int i = 0; i < 100000000; i++) {
            value += 1;
        }
    }
    return value   
 }

public static void main(String[] args) {
    // this might also take rather long
    loop();
    // as well as this
    // System.out.println(loop());
}
}

这里编译器将无法优化 loop() 中的循环，因为它可能会从其他各种类中调用，因此它将在所有情况下都执行。

【讨论】：

  • eclipse杀不掉怎么办？
  • 谢谢。是的，返回值会减慢程序的速度。
  • 我猜，你现在不知道“HotSpot”是什么意思。如果没有，其他代码是否可以调用该方法并不重要。 HotSpot 优化器仍然能够优化这一特定调用，这就是它的全部意义所在。
【解决方案5】：

为什么在打印结果的值时执行需要时间？请注意，如果我不打印值，相同的循环会立即结束。

说实话，我在 eclipse(windows) 中运行了您的代码，即使您注释 system.out.println 行，它也会继续运行。我在调试模式下再次检查（如果您打开调试透视图，您将在（默认情况下）左上角看到所有正在运行的应用程序。）

但是，如果它对您来说运行得很快，那么最合理的答案是这是因为 java 编译器/JVM 优化。我们都知道，尽管 java 是一种解释（主要）语言，但它的速度很快，因为它将源代码转换为字节码，使用 JIT 编译器，热点等。

为什么eclipse不能杀死程序？

我可以在eclipse(windows)中成功杀死程序。特定的 Eclipse 版本或 linux 可能存在一些问题。（不确定）。当 eclipse 无法终止程序时，一个快速的谷歌搜索给出了多种场景。

【讨论】：

    猜你喜欢
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 1970-01-01
    • 2018-01-14
    相关资源
    最近更新 更多
    热门标签
    Java Python linux javascript Mysql C# Docker 算法 前端 SpringBoot Redis Vue spring 设计模式 .net core .net kubernetes c++ 数据库 数据结构 大数据 js 机器学习 微服务 Android Go 程序员 面试 JVM ASP.net core 云原生 人工智能 后端 PHP git CSS golang k8s Nginx Django mybatis 深度学习 多线程 React 架构 devops 爬虫 云计算 Spring Boot LeetCode