Uploaded image for project: 'JDK'
  1. JDK
  2. JDK-8129847

Compiling methods generated by Nashorn triggers high memory usage in C2

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: P3
    • Resolution: Fixed
    • Affects Version/s: 8, 9
    • Fix Version/s: 9
    • Component/s: hotspot
    • Subcomponent:
    • Resolved In Build:
      b97

      Backports

        Description

        We saw an issue where native memory usage out of the box on large machines with many cores had increased a lot between JDK 7 and JDK 8:

        jdk 7 uses about 550 mb of memory
        jdk 8 goes up to 1.5 gb of memory

        The issue seemed to be that with tiered compilation and many compiler threads, we compiled a lot more methods in JDK 8 which lead to a lot bigger native memory footprint.

        The native memory usage was reduced by running with:

        -XX:CICompilerCount=2' -XX:-TieredCompilation -XX:CompileThreshold=80000 -XX:ReservedCodeCacheSize=48m

        We never tried each of these flags separately in order to find out which gave the biggest impact.

        We should look over if any of our default values gets too big on large machines with a lot of memory and CPUs.
        1. node_count.html
          18 kB
          Zoltan Majo
        2. reproduce-jdk-bug.tar.gz
          406 kB
          Vladimir Kozlov

          Issue Links

            Activity

            Hide
            vlivanov Vladimir Ivanov added a comment -
            ILW=big memory usage, possible memory leak;in case of lots of compiler threads;none=MMH=>P3
            Show
            vlivanov Vladimir Ivanov added a comment - ILW=big memory usage, possible memory leak;in case of lots of compiler threads;none=MMH=>P3
            Hide
            zmajo Zoltan Majo added a comment -
            Hi,


            here is an intermediary report of my understanding of (and progress with) the issue.


            Short summary
            =============

            The high memory usage of the compiler is caused by incremental inlining and optimizations executed after incremental inlining. The impact of incremental inlining on memory usage is around 5X as large as the impact of the optimizations following it. As a workaround, the memory usage of the compiler can be reduced by changing the LiveNodeCountInliningCutoff threshold from 40'000 to 20'000 (the value used by JDK7).


            Experiments
            ===========

            I executed the reproducer as suggested by Vladimir K. I used a locally-built OpenJDK build that is based on a recent checkout from:

            http://hg.openjdk.java.net/jdk8u/jdk8u-dev/

            For the investigation, I traced the memory usage of the following two methods while the methods are compiled with C2:
            (1) jdk.nashorn.internal.scripts.Script$Recompilation$190$341313AZ$r::L:100$loadLib$L:8141$parse$subscripts (no on the methods compiled)
            (2) jdk.nashorn.internal.scripts.Script$Recompilation$181$345772AA$r::L:100$loadLib$L:8141$prog1 (no restrictions on the methods compiled)

            For both methods I observe two "jumps" in memory usage:
            (1) during performing incremental inlining (for the first time) and
            (2) after escape analysis, but still in the optimization phase (I have not precisely identified the location yet).

            Here are some numbers about the jumps in the memory usage:

            Jump (1)
                     | Usage (RSS in MB)
            Method | Before incremental inlining | After incremental inlining | Difference
            ========================================================================================
            (1) | 524 | 779 | 255
            (2) | 204 | 470 | 266

            Jump (2)
                     | Usage (RSS in MB)
            Method | Just after escape analysis | At the end of the | Difference
            ====================================================================================
            (1) | 779 | 825 | 46
            (2) | 484 | 528 | 44


            Jump 1 (the jump during incremental inlining) is around 5X larger than Jump 2 (the jump that happens after escape analysis).

            As Vladimir pointed out, the compiler relases memory it uses. The problem is that most memory pages are returned to the memory allocator, but not to the OS. So it seems we are not leaking (a lot of) memory. Here is some output that was generated using the mallinfo() call after the last compilation (in CompileBroker::invoke_compiler_on_method):

            ...
            Looking into mallinfo
            Non-mmapped space allocated: 907 407 360 bytes
            Space allocated in mmapped regions: 18 440 192 bytes
            The total number of bytes in fastbin free blocks: 73552 bytes
            The total number of bytes used by in-use allocations: 51 851 344 bytes
            The total number of bytes in free blocks: 855 556 016 bytes
            The total amount of releasable free space at the top of the heap: 38 162 144 bytes
            ...


            Problems
            ========

            There are two problems that must be addressed:
            (1) the high memory usage of incremental inlining;
            (2) the high memory usage of the optimization phases following escape analysis.

            Problem (1) and (2) are closely related. As I understand it, incremental inlining produces a large number of nodes. Subsequent phases occupy an amount of memory that is proportional to the number of nodes generated by incremental inlining.

            Problem 1 is currently tracked by JDK-8131702. The fix earlier proposed by Vladimir (see above) should reduce the impact of Problem 2.


            Workaround
            ==========

            The LiveNodeCountInliningCutoff flag sets a bound for incremental inlining. In JDK8, the flag is set by default to 20'000. In JDK8 and JDK9 the flag is set to 40'000 (see JDK-8058148 for details).

            I ran the reproducer with 7u80 and 8u60. In case of 8u60 I used both LiveNodeCountInliningCutoff=20'000 and LiveNodeCountInliningCutoff=40'000. Here are the results:

            JDK version | LiveNodeCountInliningCutoff | RSS (MB) | Total runtime | Compilation time
            ===================================================================================
            7u80 | 20'000 | 163 | 1m0s | 11s
            8u60 | 20'000 | 522 | 2m46s | 127s
            8u60 | 40'000 | 976 | 6m54s | 371s

            Running 8u60 with a reduced LiveNodeCountInliningCutoff reduces the peak memory usage by 2. The differences in the runtime between the two 8u60 configurations are due to the different amount of time time spent in the compiler (the measurement was executed with -Xbatch). Also, 7u80 and 8u60 use different JavaScript engines.

            Reducing the LiveNodeCountInliningCutoff might be a workaround in cases when memory limitations cause the compiler to exit with an out of memory error.


            I'll continue the investigation by looking into ways to reduce the memory usage of C2.

            Thank you and best regards,


            Zoltan
            Show
            zmajo Zoltan Majo added a comment - Hi, here is an intermediary report of my understanding of (and progress with) the issue. Short summary ============= The high memory usage of the compiler is caused by incremental inlining and optimizations executed after incremental inlining. The impact of incremental inlining on memory usage is around 5X as large as the impact of the optimizations following it. As a workaround, the memory usage of the compiler can be reduced by changing the LiveNodeCountInliningCutoff threshold from 40'000 to 20'000 (the value used by JDK7). Experiments =========== I executed the reproducer as suggested by Vladimir K. I used a locally-built OpenJDK build that is based on a recent checkout from: http://hg.openjdk.java.net/jdk8u/jdk8u-dev/ For the investigation, I traced the memory usage of the following two methods while the methods are compiled with C2: (1) jdk.nashorn.internal.scripts.Script$Recompilation$190$341313AZ$r::L:100$loadLib$L:8141$parse$subscripts (no on the methods compiled) (2) jdk.nashorn.internal.scripts.Script$Recompilation$181$345772AA$r::L:100$loadLib$L:8141$prog1 (no restrictions on the methods compiled) For both methods I observe two "jumps" in memory usage: (1) during performing incremental inlining (for the first time) and (2) after escape analysis, but still in the optimization phase (I have not precisely identified the location yet). Here are some numbers about the jumps in the memory usage: Jump (1)          | Usage (RSS in MB) Method | Before incremental inlining | After incremental inlining | Difference ======================================================================================== (1) | 524 | 779 | 255 (2) | 204 | 470 | 266 Jump (2)          | Usage (RSS in MB) Method | Just after escape analysis | At the end of the | Difference ==================================================================================== (1) | 779 | 825 | 46 (2) | 484 | 528 | 44 Jump 1 (the jump during incremental inlining) is around 5X larger than Jump 2 (the jump that happens after escape analysis). As Vladimir pointed out, the compiler relases memory it uses. The problem is that most memory pages are returned to the memory allocator, but not to the OS. So it seems we are not leaking (a lot of) memory. Here is some output that was generated using the mallinfo() call after the last compilation (in CompileBroker::invoke_compiler_on_method): ... Looking into mallinfo Non-mmapped space allocated: 907 407 360 bytes Space allocated in mmapped regions: 18 440 192 bytes The total number of bytes in fastbin free blocks: 73552 bytes The total number of bytes used by in-use allocations: 51 851 344 bytes The total number of bytes in free blocks: 855 556 016 bytes The total amount of releasable free space at the top of the heap: 38 162 144 bytes ... Problems ======== There are two problems that must be addressed: (1) the high memory usage of incremental inlining; (2) the high memory usage of the optimization phases following escape analysis. Problem (1) and (2) are closely related. As I understand it, incremental inlining produces a large number of nodes. Subsequent phases occupy an amount of memory that is proportional to the number of nodes generated by incremental inlining. Problem 1 is currently tracked by JDK-8131702 . The fix earlier proposed by Vladimir (see above) should reduce the impact of Problem 2. Workaround ========== The LiveNodeCountInliningCutoff flag sets a bound for incremental inlining. In JDK8, the flag is set by default to 20'000. In JDK8 and JDK9 the flag is set to 40'000 (see JDK-8058148 for details). I ran the reproducer with 7u80 and 8u60. In case of 8u60 I used both LiveNodeCountInliningCutoff=20'000 and LiveNodeCountInliningCutoff=40'000. Here are the results: JDK version | LiveNodeCountInliningCutoff | RSS (MB) | Total runtime | Compilation time =================================================================================== 7u80 | 20'000 | 163 | 1m0s | 11s 8u60 | 20'000 | 522 | 2m46s | 127s 8u60 | 40'000 | 976 | 6m54s | 371s Running 8u60 with a reduced LiveNodeCountInliningCutoff reduces the peak memory usage by 2. The differences in the runtime between the two 8u60 configurations are due to the different amount of time time spent in the compiler (the measurement was executed with -Xbatch). Also, 7u80 and 8u60 use different JavaScript engines. Reducing the LiveNodeCountInliningCutoff might be a workaround in cases when memory limitations cause the compiler to exit with an out of memory error. I'll continue the investigation by looking into ways to reduce the memory usage of C2. Thank you and best regards, Zoltan
            Hide
            zmajo Zoltan Majo added a comment -
            Vladimir K and I were working on a solution. Here is the latest pre-RFR webrev that we are currently discussing about:

            [9]: http://cr.openjdk.java.net/~zmajo/code/8129847/9/webrev.03/
            [8]: http://cr.openjdk.java.net/~zmajo/code/8129847/8u/webrev.03/

            Some data showing the effect of the newly added RenumberLiveNodes flag is here:

            http://cr.openjdk.java.net/~zmajo/code/8129847/node_count.html

            (and also attached to this bug).
            Show
            zmajo Zoltan Majo added a comment - Vladimir K and I were working on a solution. Here is the latest pre-RFR webrev that we are currently discussing about: [9]: http://cr.openjdk.java.net/~zmajo/code/8129847/9/webrev.03/ [8]: http://cr.openjdk.java.net/~zmajo/code/8129847/8u/webrev.03/ Some data showing the effect of the newly added RenumberLiveNodes flag is here: http://cr.openjdk.java.net/~zmajo/code/8129847/node_count.html (and also attached to this bug).
            Hide
            hgupdate HG Updates added a comment -
            URL: http://hg.openjdk.java.net/jdk9/hs-comp/hotspot/rev/da497ea6c120
            User: zmajo
            Date: 2015-12-01 09:58:46 +0000
            Show
            hgupdate HG Updates added a comment - URL: http://hg.openjdk.java.net/jdk9/hs-comp/hotspot/rev/da497ea6c120 User: zmajo Date: 2015-12-01 09:58:46 +0000
            Hide
            hgupdate HG Updates added a comment -
            URL: http://hg.openjdk.java.net/jdk9/jdk9/hotspot/rev/da497ea6c120
            User: lana
            Date: 2015-12-16 19:10:45 +0000
            Show
            hgupdate HG Updates added a comment - URL: http://hg.openjdk.java.net/jdk9/jdk9/hotspot/rev/da497ea6c120 User: lana Date: 2015-12-16 19:10:45 +0000

              People

              • Assignee:
                zmajo Zoltan Majo
                Reporter:
                mcastegr Mattis Castegren (Inactive)
              • Votes:
                0 Vote for this issue
                Watchers:
                7 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved: