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

OptimizeStringConcat fails on pre-sized StringBuilder shapes

    Details

    • Type: Bug
    • Status: Closed
    • Priority: P2
    • Resolution: Fixed
    • Affects Version/s: 9
    • Fix Version/s: 9
    • Component/s: hotspot
    • Labels:
      None
    • Subcomponent:
    • Resolved In Build:
      b105
    • Verification:
      Verified

      Description

      A sample benchmark:

          @Benchmark
          @CompilerControl(CompilerControl.Mode.DONT_INLINE)
          public String explicitSized() throws Exception {
              String time = String.valueOf(System.nanoTime());
              String thread = Thread.currentThread().getName();
              String m = method;
              return new StringBuilder(63 + time.length() + thread.length() + m.length())
                      .append("[")
                      .append(time)
                      .append("] ")
                      .append(thread)
                      .append(":")
                      .append("Calling an application method \"")
                      .append(m)
                      .append("\" without fear and prejudice.")
                      .toString();
          }

      This benchmark regresses severely with Compact Strings. Turning OptimizeStringConcat off does not degrade performance further, which means it is broken with Compact Strings to begin with. The disassembly confirms it. Also see the (broken) workaround patch below:

      # JDK 9 Baseline
      LogLineBench.explicitSized: 83.267 ± 3.021 ns/op
      LogLineBench.explicitSized:·gc.alloc.rate.norm: 384.000 ± 0.001 B/op

      # JDK 9 Baseline, -XX:-OptimizeStringConcat
      LogLineBench.explicitSized: 190.090 ± 5.893 ns/op
      LogLineBench.explicitSized:·gc.alloc.rate.norm: 1296.000 ± 0.001 B/op

      # JDK 9 Compact Strings
      LogLineBench.explicitSized: 148.536 ± 5.032 ns/op
      LogLineBench.explicitSized:·gc.alloc.rate.norm: 704.000 ± 0.001 B/op

      # JDK 9 Compact Strings, -XX:-OptimizeStringConcat
      LogLineBench.explicitSized: 143.668 ± 7.654 ns/op
      LogLineBench.explicitSized:·gc.alloc.rate.norm: 704.000 ± 0.001 B/op
      1. TestPresizedStringBuilder.java
        2 kB
        Tobias Hartmann
      1. graph.png
        10 kB

        Issue Links

          Activity

          Hide
          shade Aleksey Shipilev added a comment -
          It would seem validate_control_flow() does not expect ConI node instead of Bool node here:
           http://cr.openjdk.java.net/~shade/8136469/poc.patch
          Show
          shade Aleksey Shipilev added a comment - It would seem validate_control_flow() does not expect ConI node instead of Bool node here:   http://cr.openjdk.java.net/~shade/8136469/poc.patch
          Hide
          shade Aleksey Shipilev added a comment -
          This issue nils when we extract the length computation into local variable:

                  int len = 63 + time.length() + thread.length() + m.length();
                  return new StringBuilder(len)
          Show
          shade Aleksey Shipilev added a comment - This issue nils when we extract the length computation into local variable:         int len = 63 + time.length() + thread.length() + m.length();         return new StringBuilder(len)
          Hide
          thartmann Tobias Hartmann added a comment -
          Thanks for the information, Aleksey. I'll have a look.
          Show
          thartmann Tobias Hartmann added a comment - Thanks for the information, Aleksey. I'll have a look.
          Hide
          thartmann Tobias Hartmann added a comment -
          I simplified the benchmark to the following method

              public static String explicitSized(String a) {
                  return new StringBuilder(a.length()).append("a").toString();
              }

          Compiling this with -XX:+PrintOptimizeStringConcat bails out with

          considering toString call in Test::explicitSized @ bci:16
          fusion would fail for
           26 Allocate === 5 6 7 8 1 ( 24 22 23 1 10 ) [[ 27 28 29 36 37 38 ]] rawptr:NotNull ( int:>=0, java/lang/Object:NotNull *, bool, top ) Test::explicitSized @ bci:0 !jvms: Test::explicitSized @ bci:0
           69 CatchProj === 68 [[ 81 ]] #0@bci -1 !jvms: Test::explicitSized @ bci:5
           68 Catch === 62 63 [[ 69 70 ]] !jvms: Test::explicitSized @ bci:5
           62 Proj === 46 [[ 68 ]] #0 !jvms: Test::explicitSized @ bci:5
           46 CallStaticJava === 53 37 25 8 1 ( 61 1 43 43 ) [[ 62 63 64 66 ]] # Static java.lang.String::length int ( java/lang/String:NotNull:exact * ) Test::explicitSized @ bci:5 !jvms: Test::explicitSized @ bci:5

          This clearly is a bug because (as you said) it does not happen when using a local variable for the length.
          However, this happens both with the baseline JDK9 and with CompactStrings. Am I missing something?
          Show
          thartmann Tobias Hartmann added a comment - I simplified the benchmark to the following method     public static String explicitSized(String a) {         return new StringBuilder(a.length()).append("a").toString();     } Compiling this with -XX:+PrintOptimizeStringConcat bails out with considering toString call in Test::explicitSized @ bci:16 fusion would fail for  26 Allocate === 5 6 7 8 1 ( 24 22 23 1 10 ) [[ 27 28 29 36 37 38 ]] rawptr:NotNull ( int:>=0, java/lang/Object:NotNull *, bool, top ) Test::explicitSized @ bci:0 !jvms: Test::explicitSized @ bci:0  69 CatchProj === 68 [[ 81 ]] # 0@bci -1 !jvms: Test::explicitSized @ bci:5  68 Catch === 62 63 [[ 69 70 ]] !jvms: Test::explicitSized @ bci:5  62 Proj === 46 [[ 68 ]] #0 !jvms: Test::explicitSized @ bci:5  46 CallStaticJava === 53 37 25 8 1 ( 61 1 43 43 ) [[ 62 63 64 66 ]] # Static java.lang.String::length int ( java/lang/String:NotNull:exact * ) Test::explicitSized @ bci:5 !jvms: Test::explicitSized @ bci:5 This clearly is a bug because (as you said) it does not happen when using a local variable for the length. However, this happens both with the baseline JDK9 and with CompactStrings. Am I missing something?
          Hide
          shade Aleksey Shipilev added a comment -
          I checked again, and can again confirm this is Compact Strings-specific issue:
           http://cr.openjdk.java.net/~shade/8136469/jdk9-vs-density.txt

          These benchmarks are part of our usual Compact Strings benchmark suite.

          Note the original issue happens on code path that bails *without* PrintOptimizeStringConcat message -- normally you would have PrintOptimizeStringConcat debug block before "fail = true", this is another thing that should be fixed. Therefore the thing you observe in your minimized case is something else.
          Show
          shade Aleksey Shipilev added a comment - I checked again, and can again confirm this is Compact Strings-specific issue:   http://cr.openjdk.java.net/~shade/8136469/jdk9-vs-density.txt These benchmarks are part of our usual Compact Strings benchmark suite. Note the original issue happens on code path that bails *without* PrintOptimizeStringConcat message -- normally you would have PrintOptimizeStringConcat debug block before "fail = true", this is another thing that should be fixed. Therefore the thing you observe in your minimized case is something else.
          Hide
          thartmann Tobias Hartmann added a comment -
          I was able to reproduce this with the latest JDK9 version (see "TestPresizedStringBuilder.java"). The problem is that the initial size of the StringBuilder depends on a static final boolean that is initialized to true at runtime. Therefore the string concatenation control flow chain contains an IfNode with a ConI (1) as input instead of the expected BoolNode and StringConcat::validate_control_flow() silently bails out (see "graph.png").
          Show
          thartmann Tobias Hartmann added a comment - I was able to reproduce this with the latest JDK9 version (see "TestPresizedStringBuilder.java"). The problem is that the initial size of the StringBuilder depends on a static final boolean that is initialized to true at runtime. Therefore the string concatenation control flow chain contains an IfNode with a ConI (1) as input instead of the expected BoolNode and StringConcat::validate_control_flow() silently bails out (see "graph.png").
          Hide
          hgupdate HG Updates added a comment -
          URL: http://hg.openjdk.java.net/jdk9/hs-comp/hotspot/rev/07efffd5d643
          User: thartmann
          Date: 2016-01-12 13:37:12 +0000
          Show
          hgupdate HG Updates added a comment - URL: http://hg.openjdk.java.net/jdk9/hs-comp/hotspot/rev/07efffd5d643 User: thartmann Date: 2016-01-12 13:37:12 +0000
          Hide
          hgupdate HG Updates added a comment -
          URL: http://hg.openjdk.java.net/jdk9/jdk9/hotspot/rev/07efffd5d643
          User: lana
          Date: 2016-02-10 21:55:30 +0000
          Show
          hgupdate HG Updates added a comment - URL: http://hg.openjdk.java.net/jdk9/jdk9/hotspot/rev/07efffd5d643 User: lana Date: 2016-02-10 21:55:30 +0000
          Hide
          thartmann Tobias Hartmann added a comment -
          Fix verified by manual inspection with attached test.
          Show
          thartmann Tobias Hartmann added a comment - Fix verified by manual inspection with attached test.

            People

            • Assignee:
              thartmann Tobias Hartmann
              Reporter:
              shade Aleksey Shipilev
            • Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: