Только поутихли страсти с первой части разбора, вышедшей на прошлой неделе, как публикую продолжение: сегодня речь пойдёт о второй задаче.
Код второй задачи:
Условие (упрощённо):
Немного расширим задачу, добавив ещё один способ форматирования строки вне конкурса:
Очевидный неправильный ответ: конкатенация — это медленно (во всяком случае — медленнее, чем
Миф о медленной конкатенации, вероятнее всего, уходит своими корнями в пример, демонстрирующий влияние иммутабельности строк на вычислительную сложность алгоритма:
Результат бенчмарка говорит сам за себя (здесь N — размер массива
Запустим бенчмарк для указанных в задаче методов:
Результат бенчмарка:
1.
2. Использованиеобман зрения результат незначительных флуктуаций.
Позволю себе ещё один бенчмарк. Будем форматировать строки в том виде, в каком их просит Graphite (средство для сбора метрик):
И кусок бенчмарка (полный код всех бенчмарков доступен на github):
Результаты бенчмарка:
1.
2. Результат
Чтобы разобраться в происходящем, глянем на байткод, который получился в результате компиляции наших методов в
Разберём в деталях, что мы видим:
Как так получилось, что один единственный дополнительный вызов
Посмотрим на конструкторы:
Оказывается, что и append-то никуда не делся — он вызывается внутри конструктора. Тем не менее, ответ кроется в этом участке кода, а именно в числе 16: авторы
Когда мы создали
С другой стороны, созданный пустым
Интересующий нас кусок кода
Когда в
Если не удаётся (когда в двойной буфер добавляемая строка по-прежнему не помещается, что у нас и произошло при добавлении идентификатора метрики metrics), то создаётся буфер, длина которого равна
Таким образом, первый вызов
Второй вызов также привёл к повторному созданию массива, так как идентификатор метрики полностью занимал весь буфер. Кроме того, что размер буфера стал равен
В нашем примере для обоих вариантов 2 и 3 HotSpot применил оптимизацию
Ниже ещё будет про особенность работы
Эта задача была самой простой из предложенных — её правильно решили 10 человек из 32 и ещё 18 участников конференции дали частично правильный ответ.
Частично правильный ответ заключался в том, что, например, методы расставлены правильно, но пояснения к ответу никакого дано не было, либо оно было верно только от части.
Самый распространённый ответ по 2 и 3 — javac выдаёт одинаковый байткод. Несмотря на то, что это не совсем так, как мы выяснили выше — данный ответ засчитывался как правильный.
В одном из пояснений было верно подмечено, что компиляция конкатенации в StringBuilder не специфицирована. В разделе 15.18.1 спецификации упоминается следующее:
Интересно, что в спецификации к Java 8 говорится о
Раз уж мы заговорили про другие версии Java, то не лишним будет попробовать собрать и прогнать бенчмарк с использованием Java 9 (JRE 9.0.4).
Неожиданный результат! Возможно даже для тех, кто внимательно следил за изменениями в Java 9: JEP-280.
Смотрим в генерируемый байткод для MetricsFormat:
и байткод для OrdinalStringFormat:
За генерацию специализированных методов
По умолчанию в
Это позволило обойти проблемы при форматировании строки с метрикой, наблюдавшиеся в сгенерированном коде для Java 8. Но так может получаться не всегда, как в случае примера из нашей задачи — результат хуже примерно на четверть. Результат получился хуже как относительно
Интересен и тот факт, что метод
Дело в том, что это не
Особенность этого примера заключается в том, что
За рамками обсуждения остались compile-time оптимизации конкатенаций, о которых можно почитать в разделе спецификации, на который уже ссылался ранее (15.18.1), что тоже довольно любопытно.
И остались без внимания незачейненные вызовы
Вот для таких методов
генерируется такой байткод:
В обоих случаях видно, что javac не предпринял каких-либо попыток для оптимизации этого. При этом в случае конкатенации теперь создаётся аж 3 экземпляра StringBuilder, второй метод тоже потяжелел.
Как это отразилось на производительности?
Ожидаемо поплохело варианту
А вот с оптимизацией pop/aload в
Код бенчмарков лежит на github: jbreak2018-strings-perf-tests.
Заключительные две части выйдут с меньшим лагом. Третья часть выйдет в середине недели.
Код второй задачи:
String format(String user, String grade, String company, String message) {
return String.format(
"Он, %s, придумал такие %s задачи. Приду на стенд %s и скажу ему %s",
user, grade, company, message);
}
String format(String user, String grade, String company, String message) {
return "Он, " + user
+ ", придумал такие " + grade
+ " задачи. Приду на стенд " + company
+ " и скажу ему " + message;
}
String format(String user, String grade, String company, String message) {
return new StringBuilder("Он, ")
.append(user)
.append(", придумал такие ")
.append(grade)
.append(" задачи. Приду на стенд ")
.append(company)
.append(" и скажу ему ")
.append(message)
.toString();
}
Условие (упрощённо):
Определить, какие методы быстрые, а какие — медленные (JRE 1.8.0_161).
Немного расширим задачу, добавив ещё один способ форматирования строки вне конкурса:
public String formatThroughMessageFormat(String user, String grade, String company, String message) {
return MessageFormat.format(
"Он, {0}, придумал такие {1} задачи. Приду на стенд {2} и скажу ему {3}",
user, grade, company, message);
}
Решение
Миф о медленной конкатенации
Очевидный неправильный ответ: конкатенация — это медленно (во всяком случае — медленнее, чем
StringBuilder).Миф о медленной конкатенации, вероятнее всего, уходит своими корнями в пример, демонстрирующий влияние иммутабельности строк на вычислительную сложность алгоритма:
public static String constructThroughConcatenation(String[] strings) {
String result = "";
for (String s : strings) {
result = result + s;
}
return result;
}
public static String constructThroughBuilder(String[] strings) {
StringBuilder sb = new StringBuilder();
for (String s : strings) {
sb.append(s);
}
return sb.toString();
}
Результат бенчмарка говорит сам за себя (здесь N — размер массива
strings):Benchmark (N) Mode Cnt Score Error Units
...builderBenchmark 10 avgt 30 0,182 ± 0,004 us/op
...builderBenchmark 100 avgt 30 1,566 ± 0,014 us/op
...builderBenchmark 1000 avgt 30 18,188 ± 0,372 us/op
...builderBenchmark 10000 avgt 30 214,308 ± 7,523 us/op
...concatenationBenchmark 10 avgt 30 0,209 ± 0,003 us/op
...concatenationBenchmark 100 avgt 30 13,220 ± 0,305 us/op
...concatenationBenchmark 1000 avgt 30 1158,463 ± 48,124 us/op
...concatenationBenchmark 10000 avgt 30 127585,013 ± 5716,547 us/op
Результаты бенчмарка целиком
# JMH version: 1.20
# VM version: JDK 1.8.0_161, VM 25.161-b12
# VM invoker: C:\Program Files\Java\jre1.8.0_161\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.builderBenchmark
# Parameters: (N = 10)
# Run progress: 0,00% complete, ETA 00:09:00
# Fork: 1 of 3
# Warmup Iteration 1: 0,251 us/op
# Warmup Iteration 2: 0,192 us/op
# Warmup Iteration 3: 0,206 us/op
# Warmup Iteration 4: 0,183 us/op
# Warmup Iteration 5: 0,181 us/op
Iteration 1: 0,180 us/op
Iteration 2: 0,181 us/op
Iteration 3: 0,188 us/op
Iteration 4: 0,180 us/op
Iteration 5: 0,202 us/op
Iteration 6: 0,192 us/op
Iteration 7: 0,195 us/op
Iteration 8: 0,178 us/op
Iteration 9: 0,179 us/op
Iteration 10: 0,192 us/op
# Run progress: 4,17% complete, ETA 00:08:47
# Fork: 2 of 3
# Warmup Iteration 1: 0,249 us/op
# Warmup Iteration 2: 0,179 us/op
# Warmup Iteration 3: 0,178 us/op
# Warmup Iteration 4: 0,178 us/op
# Warmup Iteration 5: 0,179 us/op
Iteration 1: 0,178 us/op
Iteration 2: 0,181 us/op
Iteration 3: 0,178 us/op
Iteration 4: 0,179 us/op
Iteration 5: 0,181 us/op
Iteration 6: 0,182 us/op
Iteration 7: 0,183 us/op
Iteration 8: 0,177 us/op
Iteration 9: 0,177 us/op
Iteration 10: 0,177 us/op
# Run progress: 8,33% complete, ETA 00:08:24
# Fork: 3 of 3
# Warmup Iteration 1: 0,249 us/op
# Warmup Iteration 2: 0,179 us/op
# Warmup Iteration 3: 0,177 us/op
# Warmup Iteration 4: 0,179 us/op
# Warmup Iteration 5: 0,179 us/op
Iteration 1: 0,180 us/op
Iteration 2: 0,180 us/op
Iteration 3: 0,178 us/op
Iteration 4: 0,178 us/op
Iteration 5: 0,181 us/op
Iteration 6: 0,180 us/op
Iteration 7: 0,180 us/op
Iteration 8: 0,179 us/op
Iteration 9: 0,182 us/op
Iteration 10: 0,178 us/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.builderBenchmark":
0,182 ±(99.9%) 0,004 us/op [Average]
(min, avg, max) = (0,177, 0,182, 0,202), stdev = 0,006
CI (99.9%): [0,178, 0,186] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 1.8.0_161, VM 25.161-b12
# VM invoker: C:\Program Files\Java\jre1.8.0_161\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.builderBenchmark
# Parameters: (N = 100)
# Run progress: 12,50% complete, ETA 00:08:01
# Fork: 1 of 3
# Warmup Iteration 1: 2,016 us/op
# Warmup Iteration 2: 1,592 us/op
# Warmup Iteration 3: 1,548 us/op
# Warmup Iteration 4: 1,557 us/op
# Warmup Iteration 5: 1,553 us/op
Iteration 1: 1,561 us/op
Iteration 2: 1,563 us/op
Iteration 3: 1,568 us/op
Iteration 4: 1,570 us/op
Iteration 5: 1,560 us/op
Iteration 6: 1,560 us/op
Iteration 7: 1,563 us/op
Iteration 8: 1,564 us/op
Iteration 9: 1,570 us/op
Iteration 10: 1,566 us/op
# Run progress: 16,67% complete, ETA 00:07:38
# Fork: 2 of 3
# Warmup Iteration 1: 2,011 us/op
# Warmup Iteration 2: 1,578 us/op
# Warmup Iteration 3: 1,556 us/op
# Warmup Iteration 4: 1,560 us/op
# Warmup Iteration 5: 1,601 us/op
Iteration 1: 1,551 us/op
Iteration 2: 1,563 us/op
Iteration 3: 1,558 us/op
Iteration 4: 1,555 us/op
Iteration 5: 1,562 us/op
Iteration 6: 1,560 us/op
Iteration 7: 1,556 us/op
Iteration 8: 1,565 us/op
Iteration 9: 1,565 us/op
Iteration 10: 1,553 us/op
# Run progress: 20,83% complete, ETA 00:07:15
# Fork: 3 of 3
# Warmup Iteration 1: 2,099 us/op
# Warmup Iteration 2: 1,769 us/op
# Warmup Iteration 3: 1,751 us/op
# Warmup Iteration 4: 1,554 us/op
# Warmup Iteration 5: 1,555 us/op
Iteration 1: 1,602 us/op
Iteration 2: 1,663 us/op
Iteration 3: 1,567 us/op
Iteration 4: 1,565 us/op
Iteration 5: 1,569 us/op
Iteration 6: 1,548 us/op
Iteration 7: 1,555 us/op
Iteration 8: 1,553 us/op
Iteration 9: 1,559 us/op
Iteration 10: 1,563 us/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.builderBenchmark":
1,566 ±(99.9%) 0,014 us/op [Average]
(min, avg, max) = (1,548, 1,566, 1,663), stdev = 0,020
CI (99.9%): [1,552, 1,580] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 1.8.0_161, VM 25.161-b12
# VM invoker: C:\Program Files\Java\jre1.8.0_161\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.builderBenchmark
# Parameters: (N = 1000)
# Run progress: 25,00% complete, ETA 00:06:52
# Fork: 1 of 3
# Warmup Iteration 1: 25,482 us/op
# Warmup Iteration 2: 17,783 us/op
# Warmup Iteration 3: 17,741 us/op
# Warmup Iteration 4: 18,389 us/op
# Warmup Iteration 5: 18,693 us/op
Iteration 1: 17,891 us/op
Iteration 2: 17,909 us/op
Iteration 3: 17,966 us/op
Iteration 4: 17,632 us/op
Iteration 5: 17,884 us/op
Iteration 6: 17,821 us/op
Iteration 7: 17,962 us/op
Iteration 8: 17,825 us/op
Iteration 9: 18,039 us/op
Iteration 10: 17,891 us/op
# Run progress: 29,17% complete, ETA 00:06:29
# Fork: 2 of 3
# Warmup Iteration 1: 23,928 us/op
# Warmup Iteration 2: 17,799 us/op
# Warmup Iteration 3: 17,615 us/op
# Warmup Iteration 4: 17,823 us/op
# Warmup Iteration 5: 17,996 us/op
Iteration 1: 17,901 us/op
Iteration 2: 18,052 us/op
Iteration 3: 18,093 us/op
Iteration 4: 17,722 us/op
Iteration 5: 17,951 us/op
Iteration 6: 17,958 us/op
Iteration 7: 18,071 us/op
Iteration 8: 18,043 us/op
Iteration 9: 17,681 us/op
Iteration 10: 17,934 us/op
# Run progress: 33,33% complete, ETA 00:06:06
# Fork: 3 of 3
# Warmup Iteration 1: 26,743 us/op
# Warmup Iteration 2: 18,281 us/op
# Warmup Iteration 3: 18,178 us/op
# Warmup Iteration 4: 18,474 us/op
# Warmup Iteration 5: 18,661 us/op
Iteration 1: 18,735 us/op
Iteration 2: 20,414 us/op
Iteration 3: 18,762 us/op
Iteration 4: 18,673 us/op
Iteration 5: 18,280 us/op
Iteration 6: 18,336 us/op
Iteration 7: 18,259 us/op
Iteration 8: 18,362 us/op
Iteration 9: 18,295 us/op
Iteration 10: 19,312 us/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.builderBenchmark":
18,188 ±(99.9%) 0,372 us/op [Average]
(min, avg, max) = (17,632, 18,188, 20,414), stdev = 0,557
CI (99.9%): [17,816, 18,561] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 1.8.0_161, VM 25.161-b12
# VM invoker: C:\Program Files\Java\jre1.8.0_161\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.builderBenchmark
# Parameters: (N = 10000)
# Run progress: 37,50% complete, ETA 00:05:44
# Fork: 1 of 3
# Warmup Iteration 1: 282,300 us/op
# Warmup Iteration 2: 225,761 us/op
# Warmup Iteration 3: 223,512 us/op
# Warmup Iteration 4: 261,430 us/op
# Warmup Iteration 5: 292,495 us/op
Iteration 1: 220,548 us/op
Iteration 2: 217,293 us/op
Iteration 3: 240,740 us/op
Iteration 4: 218,483 us/op
Iteration 5: 216,646 us/op
Iteration 6: 211,005 us/op
Iteration 7: 209,140 us/op
Iteration 8: 204,410 us/op
Iteration 9: 208,205 us/op
Iteration 10: 217,127 us/op
# Run progress: 41,67% complete, ETA 00:05:21
# Fork: 2 of 3
# Warmup Iteration 1: 259,280 us/op
# Warmup Iteration 2: 230,647 us/op
# Warmup Iteration 3: 209,753 us/op
# Warmup Iteration 4: 215,611 us/op
# Warmup Iteration 5: 210,592 us/op
Iteration 1: 203,746 us/op
Iteration 2: 208,074 us/op
Iteration 3: 207,905 us/op
Iteration 4: 213,764 us/op
Iteration 5: 206,427 us/op
Iteration 6: 207,121 us/op
Iteration 7: 215,708 us/op
Iteration 8: 213,091 us/op
Iteration 9: 211,328 us/op
Iteration 10: 204,837 us/op
# Run progress: 45,83% complete, ETA 00:04:58
# Fork: 3 of 3
# Warmup Iteration 1: 253,784 us/op
# Warmup Iteration 2: 227,220 us/op
# Warmup Iteration 3: 202,387 us/op
# Warmup Iteration 4: 211,402 us/op
# Warmup Iteration 5: 207,545 us/op
Iteration 1: 206,279 us/op
Iteration 2: 205,982 us/op
Iteration 3: 211,830 us/op
Iteration 4: 238,729 us/op
Iteration 5: 237,315 us/op
Iteration 6: 238,384 us/op
Iteration 7: 223,376 us/op
Iteration 8: 210,594 us/op
Iteration 9: 200,957 us/op
Iteration 10: 200,183 us/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.builderBenchmark":
214,308 ±(99.9%) 7,523 us/op [Average]
(min, avg, max) = (200,183, 214,308, 240,740), stdev = 11,260
CI (99.9%): [206,785, 221,831] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 1.8.0_161, VM 25.161-b12
# VM invoker: C:\Program Files\Java\jre1.8.0_161\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.concatenationBenchmark
# Parameters: (N = 10)
# Run progress: 50,00% complete, ETA 00:04:35
# Fork: 1 of 3
# Warmup Iteration 1: 0,273 us/op
# Warmup Iteration 2: 0,201 us/op
# Warmup Iteration 3: 0,209 us/op
# Warmup Iteration 4: 0,208 us/op
# Warmup Iteration 5: 0,208 us/op
Iteration 1: 0,208 us/op
Iteration 2: 0,207 us/op
Iteration 3: 0,208 us/op
Iteration 4: 0,208 us/op
Iteration 5: 0,208 us/op
Iteration 6: 0,208 us/op
Iteration 7: 0,208 us/op
Iteration 8: 0,213 us/op
Iteration 9: 0,206 us/op
Iteration 10: 0,206 us/op
# Run progress: 54,17% complete, ETA 00:04:12
# Fork: 2 of 3
# Warmup Iteration 1: 0,301 us/op
# Warmup Iteration 2: 0,207 us/op
# Warmup Iteration 3: 0,204 us/op
# Warmup Iteration 4: 0,206 us/op
# Warmup Iteration 5: 0,206 us/op
Iteration 1: 0,208 us/op
Iteration 2: 0,207 us/op
Iteration 3: 0,206 us/op
Iteration 4: 0,206 us/op
Iteration 5: 0,208 us/op
Iteration 6: 0,205 us/op
Iteration 7: 0,207 us/op
Iteration 8: 0,221 us/op
Iteration 9: 0,214 us/op
Iteration 10: 0,207 us/op
# Run progress: 58,33% complete, ETA 00:03:49
# Fork: 3 of 3
# Warmup Iteration 1: 0,273 us/op
# Warmup Iteration 2: 0,199 us/op
# Warmup Iteration 3: 0,213 us/op
# Warmup Iteration 4: 0,206 us/op
# Warmup Iteration 5: 0,208 us/op
Iteration 1: 0,210 us/op
Iteration 2: 0,220 us/op
Iteration 3: 0,208 us/op
Iteration 4: 0,205 us/op
Iteration 5: 0,205 us/op
Iteration 6: 0,209 us/op
Iteration 7: 0,210 us/op
Iteration 8: 0,209 us/op
Iteration 9: 0,208 us/op
Iteration 10: 0,208 us/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.concatenationBenchmark":
0,209 ±(99.9%) 0,003 us/op [Average]
(min, avg, max) = (0,205, 0,209, 0,221), stdev = 0,004
CI (99.9%): [0,206, 0,211] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 1.8.0_161, VM 25.161-b12
# VM invoker: C:\Program Files\Java\jre1.8.0_161\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.concatenationBenchmark
# Parameters: (N = 100)
# Run progress: 62,50% complete, ETA 00:03:26
# Fork: 1 of 3
# Warmup Iteration 1: 17,351 us/op
# Warmup Iteration 2: 13,141 us/op
# Warmup Iteration 3: 13,015 us/op
# Warmup Iteration 4: 13,004 us/op
# Warmup Iteration 5: 13,073 us/op
Iteration 1: 13,056 us/op
Iteration 2: 13,158 us/op
Iteration 3: 13,005 us/op
Iteration 4: 13,126 us/op
Iteration 5: 13,001 us/op
Iteration 6: 13,072 us/op
Iteration 7: 13,085 us/op
Iteration 8: 13,063 us/op
Iteration 9: 13,196 us/op
Iteration 10: 13,084 us/op
# Run progress: 66,67% complete, ETA 00:03:03
# Fork: 2 of 3
# Warmup Iteration 1: 17,545 us/op
# Warmup Iteration 2: 13,517 us/op
# Warmup Iteration 3: 13,500 us/op
# Warmup Iteration 4: 13,089 us/op
# Warmup Iteration 5: 13,099 us/op
Iteration 1: 13,312 us/op
Iteration 2: 13,689 us/op
Iteration 3: 13,157 us/op
Iteration 4: 13,532 us/op
Iteration 5: 14,263 us/op
Iteration 6: 14,110 us/op
Iteration 7: 14,207 us/op
Iteration 8: 13,167 us/op
Iteration 9: 13,530 us/op
Iteration 10: 13,127 us/op
# Run progress: 70,83% complete, ETA 00:02:40
# Fork: 3 of 3
# Warmup Iteration 1: 17,107 us/op
# Warmup Iteration 2: 12,677 us/op
# Warmup Iteration 3: 12,549 us/op
# Warmup Iteration 4: 12,714 us/op
# Warmup Iteration 5: 14,134 us/op
Iteration 1: 13,898 us/op
Iteration 2: 13,726 us/op
Iteration 3: 12,997 us/op
Iteration 4: 12,736 us/op
Iteration 5: 12,702 us/op
Iteration 6: 12,670 us/op
Iteration 7: 12,690 us/op
Iteration 8: 12,735 us/op
Iteration 9: 12,761 us/op
Iteration 10: 12,750 us/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.concatenationBenchmark":
13,220 ±(99.9%) 0,305 us/op [Average]
(min, avg, max) = (12,670, 13,220, 14,263), stdev = 0,456
CI (99.9%): [12,915, 13,525] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 1.8.0_161, VM 25.161-b12
# VM invoker: C:\Program Files\Java\jre1.8.0_161\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.concatenationBenchmark
# Parameters: (N = 1000)
# Run progress: 75,00% complete, ETA 00:02:17
# Fork: 1 of 3
# Warmup Iteration 1: 2069,805 us/op
# Warmup Iteration 2: 1256,239 us/op
# Warmup Iteration 3: 1094,567 us/op
# Warmup Iteration 4: 1088,928 us/op
# Warmup Iteration 5: 1128,676 us/op
Iteration 1: 1098,263 us/op
Iteration 2: 1092,322 us/op
Iteration 3: 1092,764 us/op
Iteration 4: 1091,264 us/op
Iteration 5: 1084,967 us/op
Iteration 6: 1082,483 us/op
Iteration 7: 1087,570 us/op
Iteration 8: 1085,939 us/op
Iteration 9: 1087,219 us/op
Iteration 10: 1099,661 us/op
# Run progress: 79,17% complete, ETA 00:01:54
# Fork: 2 of 3
# Warmup Iteration 1: 1886,339 us/op
# Warmup Iteration 2: 1079,598 us/op
# Warmup Iteration 3: 1249,267 us/op
# Warmup Iteration 4: 1223,656 us/op
# Warmup Iteration 5: 1155,596 us/op
Iteration 1: 1074,649 us/op
Iteration 2: 1158,081 us/op
Iteration 3: 1156,362 us/op
Iteration 4: 1164,930 us/op
Iteration 5: 1109,143 us/op
Iteration 6: 1172,856 us/op
Iteration 7: 1277,790 us/op
Iteration 8: 1201,096 us/op
Iteration 9: 1111,431 us/op
Iteration 10: 1267,544 us/op
# Run progress: 83,33% complete, ETA 00:01:31
# Fork: 3 of 3
# Warmup Iteration 1: 2372,316 us/op
# Warmup Iteration 2: 1381,800 us/op
# Warmup Iteration 3: 1360,184 us/op
# Warmup Iteration 4: 1131,667 us/op
# Warmup Iteration 5: 1209,669 us/op
Iteration 1: 1278,702 us/op
Iteration 2: 1219,975 us/op
Iteration 3: 1141,188 us/op
Iteration 4: 1244,753 us/op
Iteration 5: 1229,355 us/op
Iteration 6: 1168,263 us/op
Iteration 7: 1153,918 us/op
Iteration 8: 1330,528 us/op
Iteration 9: 1207,424 us/op
Iteration 10: 1183,450 us/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.concatenationBenchmark":
1158,463 ±(99.9%) 48,124 us/op [Average]
(min, avg, max) = (1074,649, 1158,463, 1330,528), stdev = 72,029
CI (99.9%): [1110,339, 1206,587] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 1.8.0_161, VM 25.161-b12
# VM invoker: C:\Program Files\Java\jre1.8.0_161\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.concatenationBenchmark
# Parameters: (N = 10000)
# Run progress: 87,50% complete, ETA 00:01:08
# Fork: 1 of 3
# Warmup Iteration 1: 551317,226 us/op
# Warmup Iteration 2: 428150,732 us/op
# Warmup Iteration 3: 416550,724 us/op
# Warmup Iteration 4: 117977,293 us/op
# Warmup Iteration 5: 121797,206 us/op
Iteration 1: 120847,573 us/op
Iteration 2: 134688,534 us/op
Iteration 3: 130307,702 us/op
Iteration 4: 122642,500 us/op
Iteration 5: 119836,801 us/op
Iteration 6: 128095,357 us/op
Iteration 7: 119841,822 us/op
Iteration 8: 125189,403 us/op
Iteration 9: 125955,061 us/op
Iteration 10: 137509,499 us/op
# Run progress: 91,67% complete, ETA 00:00:46
# Fork: 2 of 3
# Warmup Iteration 1: 602435,410 us/op
# Warmup Iteration 2: 404409,425 us/op
# Warmup Iteration 3: 404721,946 us/op
# Warmup Iteration 4: 133065,650 us/op
# Warmup Iteration 5: 123633,597 us/op
Iteration 1: 117683,792 us/op
Iteration 2: 126726,151 us/op
Iteration 3: 125225,846 us/op
Iteration 4: 128106,852 us/op
Iteration 5: 121581,390 us/op
Iteration 6: 128516,807 us/op
Iteration 7: 145913,920 us/op
Iteration 8: 134438,346 us/op
Iteration 9: 118692,163 us/op
Iteration 10: 125122,644 us/op
# Run progress: 95,83% complete, ETA 00:00:23
# Fork: 3 of 3
# Warmup Iteration 1: 515801,468 us/op
# Warmup Iteration 2: 403393,041 us/op
# Warmup Iteration 3: 388443,058 us/op
# Warmup Iteration 4: 127654,236 us/op
# Warmup Iteration 5: 117518,788 us/op
Iteration 1: 119643,439 us/op
Iteration 2: 137466,542 us/op
Iteration 3: 146242,312 us/op
Iteration 4: 143566,288 us/op
Iteration 5: 138948,391 us/op
Iteration 6: 120434,984 us/op
Iteration 7: 126233,747 us/op
Iteration 8: 118765,491 us/op
Iteration 9: 121795,027 us/op
Iteration 10: 117532,020 us/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.concatenationBenchmark":
127585,013 ±(99.9%) 5716,547 us/op [Average]
(min, avg, max) = (117532,020, 127585,013, 146242,312), stdev = 8556,259
CI (99.9%): [121868,467, 133301,560] (assumes normal distribution)
# Run complete. Total time: 00:09:14
Benchmark (N) Mode Cnt Score Error Units
ImmutableStringBenchmark.builderBenchmark 10 avgt 30 0,182 ± 0,004 us/op
ImmutableStringBenchmark.builderBenchmark 100 avgt 30 1,566 ± 0,014 us/op
ImmutableStringBenchmark.builderBenchmark 1000 avgt 30 18,188 ± 0,372 us/op
ImmutableStringBenchmark.builderBenchmark 10000 avgt 30 214,308 ± 7,523 us/op
ImmutableStringBenchmark.concatenationBenchmark 10 avgt 30 0,209 ± 0,003 us/op
ImmutableStringBenchmark.concatenationBenchmark 100 avgt 30 13,220 ± 0,305 us/op
ImmutableStringBenchmark.concatenationBenchmark 1000 avgt 30 1158,463 ± 48,124 us/op
ImmutableStringBenchmark.concatenationBenchmark 10000 avgt 30 127585,013 ± 5716,547 us/op
O(n^2) против O(n) — очевидное превосходство StringBuilder над конкатенацией.Бенчмарк и разрушение мифа
Запустим бенчмарк для указанных в задаче методов:
formatThroughPattern— использованиеString.format()formatThroughConcatenation— использование конкатенации строкformatThroughBuilder— использованиеStringBuilderformatThroughMessageFormat— использованиеMessageFormat.format().
Код бенчмарка
package ru.gnkoshelev.jbreak2018.perf_tests.strings;
import org.openjdk.jmh.annotations.Benchmark;
import org.openjdk.jmh.annotations.BenchmarkMode;
import org.openjdk.jmh.annotations.Fork;
import org.openjdk.jmh.annotations.Measurement;
import org.openjdk.jmh.annotations.Mode;
import org.openjdk.jmh.annotations.OutputTimeUnit;
import org.openjdk.jmh.annotations.Scope;
import org.openjdk.jmh.annotations.Setup;
import org.openjdk.jmh.annotations.State;
import org.openjdk.jmh.annotations.Warmup;
import org.openjdk.jmh.infra.Blackhole;
import java.util.concurrent.TimeUnit;
import static ru.gnkoshelev.jbreak2018.perf_tests.strings.OrdinalStringFormat.formatThroughBuilder;
import static ru.gnkoshelev.jbreak2018.perf_tests.strings.OrdinalStringFormat.formatThroughConcatenation;
import static ru.gnkoshelev.jbreak2018.perf_tests.strings.OrdinalStringFormat.formatThroughMessageFormat;
import static ru.gnkoshelev.jbreak2018.perf_tests.strings.OrdinalStringFormat.formatThroughPattern;
/**
* Created by kgn on 16.03.2018.
*/
@Fork(value = 3, warmups = 0)
@Warmup(iterations = 5, time = 1_500, timeUnit = TimeUnit.MILLISECONDS)
@Measurement(iterations = 10, time = 1_500, timeUnit = TimeUnit.MILLISECONDS)
@OutputTimeUnit(value = TimeUnit.NANOSECONDS)
@BenchmarkMode(Mode.AverageTime)
@State(Scope.Benchmark)
public class OrdinalStringFormatBenchmark {
public String user;
public String grade;
public String message;
public String company;
@Setup
public void setup() {
user = "молодец";
grade = "хорошие";
company = "Контура";
message = "спасибо";
}
@Benchmark
public void formatThroughPatternBenchmark(Blackhole bh) {
bh.consume(formatThroughPattern(user, company, grade, message));
}
@Benchmark
public void formatThroughConcatenationBenchmark(Blackhole bh) {
bh.consume(formatThroughConcatenation(user, company, grade, message));
}
@Benchmark
public void formatThroughBuilderBenchmark(Blackhole bh) {
bh.consume(formatThroughBuilder(user, company, grade, message));
}
@Benchmark
public void formatThroughMessageFormatBenchmark(Blackhole bh) {
bh.consume(formatThroughMessageFormat(user, company, grade, message));
}
}
Результат бенчмарка:
Benchmark Mode Cnt Score Error Units
...formatThroughBuilderBenchmark avgt 30 50,719 ± 1,139 ns/op
...formatThroughConcatenationBenchmark avgt 30 49,416 ± 0,435 ns/op
...formatThroughMessageFormatBenchmark avgt 30 1018,011 ± 12,805 ns/op
...formatThroughPatternBenchmark avgt 30 1506,341 ± 21,927 ns/op
Результаты бенчмарка целиком
# JMH version: 1.20
# VM version: JDK 1.8.0_161, VM 25.161-b12
# VM invoker: C:\Program Files\Java\jre1.8.0_161\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.OrdinalStringFormatBenchmark.formatThroughBuilderBenchmark
# Run progress: 0,00% complete, ETA 00:04:30
# Fork: 1 of 3
# Warmup Iteration 1: 66,501 ns/op
# Warmup Iteration 2: 60,551 ns/op
# Warmup Iteration 3: 56,899 ns/op
# Warmup Iteration 4: 49,136 ns/op
# Warmup Iteration 5: 48,549 ns/op
Iteration 1: 52,092 ns/op
Iteration 2: 49,894 ns/op
Iteration 3: 54,802 ns/op
Iteration 4: 53,570 ns/op
Iteration 5: 50,592 ns/op
Iteration 6: 51,676 ns/op
Iteration 7: 51,835 ns/op
Iteration 8: 49,216 ns/op
Iteration 9: 53,597 ns/op
Iteration 10: 50,949 ns/op
# Run progress: 8,33% complete, ETA 00:04:13
# Fork: 2 of 3
# Warmup Iteration 1: 64,670 ns/op
# Warmup Iteration 2: 51,154 ns/op
# Warmup Iteration 3: 49,878 ns/op
# Warmup Iteration 4: 49,587 ns/op
# Warmup Iteration 5: 52,958 ns/op
Iteration 1: 53,521 ns/op
Iteration 2: 53,372 ns/op
Iteration 3: 52,264 ns/op
Iteration 4: 50,248 ns/op
Iteration 5: 50,198 ns/op
Iteration 6: 49,958 ns/op
Iteration 7: 49,277 ns/op
Iteration 8: 49,983 ns/op
Iteration 9: 50,250 ns/op
Iteration 10: 50,128 ns/op
# Run progress: 16,67% complete, ETA 00:03:49
# Fork: 3 of 3
# Warmup Iteration 1: 64,392 ns/op
# Warmup Iteration 2: 50,621 ns/op
# Warmup Iteration 3: 48,771 ns/op
# Warmup Iteration 4: 48,909 ns/op
# Warmup Iteration 5: 49,029 ns/op
Iteration 1: 49,144 ns/op
Iteration 2: 48,941 ns/op
Iteration 3: 49,632 ns/op
Iteration 4: 49,275 ns/op
Iteration 5: 48,470 ns/op
Iteration 6: 48,599 ns/op
Iteration 7: 50,489 ns/op
Iteration 8: 48,866 ns/op
Iteration 9: 50,790 ns/op
Iteration 10: 49,945 ns/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.OrdinalStringFormatBenchmark.formatThroughBuilderBenchmark":
50,719 ±(99.9%) 1,139 ns/op [Average]
(min, avg, max) = (48,470, 50,719, 54,802), stdev = 1,704
CI (99.9%): [49,580, 51,858] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 1.8.0_161, VM 25.161-b12
# VM invoker: C:\Program Files\Java\jre1.8.0_161\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.OrdinalStringFormatBenchmark.formatThroughConcatenationBenchmark
# Run progress: 25,00% complete, ETA 00:03:26
# Fork: 1 of 3
# Warmup Iteration 1: 64,954 ns/op
# Warmup Iteration 2: 49,711 ns/op
# Warmup Iteration 3: 49,847 ns/op
# Warmup Iteration 4: 49,832 ns/op
# Warmup Iteration 5: 48,330 ns/op
Iteration 1: 48,820 ns/op
Iteration 2: 48,948 ns/op
Iteration 3: 48,992 ns/op
Iteration 4: 48,912 ns/op
Iteration 5: 49,423 ns/op
Iteration 6: 51,057 ns/op
Iteration 7: 49,861 ns/op
Iteration 8: 49,339 ns/op
Iteration 9: 49,602 ns/op
Iteration 10: 49,135 ns/op
# Run progress: 33,33% complete, ETA 00:03:03
# Fork: 2 of 3
# Warmup Iteration 1: 63,647 ns/op
# Warmup Iteration 2: 49,904 ns/op
# Warmup Iteration 3: 49,307 ns/op
# Warmup Iteration 4: 48,602 ns/op
# Warmup Iteration 5: 49,369 ns/op
Iteration 1: 49,388 ns/op
Iteration 2: 48,579 ns/op
Iteration 3: 50,546 ns/op
Iteration 4: 50,421 ns/op
Iteration 5: 49,246 ns/op
Iteration 6: 48,432 ns/op
Iteration 7: 49,458 ns/op
Iteration 8: 50,071 ns/op
Iteration 9: 49,405 ns/op
Iteration 10: 49,432 ns/op
# Run progress: 41,67% complete, ETA 00:02:40
# Fork: 3 of 3
# Warmup Iteration 1: 64,515 ns/op
# Warmup Iteration 2: 49,747 ns/op
# Warmup Iteration 3: 49,217 ns/op
# Warmup Iteration 4: 49,306 ns/op
# Warmup Iteration 5: 48,832 ns/op
Iteration 1: 50,280 ns/op
Iteration 2: 50,300 ns/op
Iteration 3: 48,426 ns/op
Iteration 4: 49,774 ns/op
Iteration 5: 48,891 ns/op
Iteration 6: 49,231 ns/op
Iteration 7: 49,051 ns/op
Iteration 8: 48,662 ns/op
Iteration 9: 49,083 ns/op
Iteration 10: 49,724 ns/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.OrdinalStringFormatBenchmark.formatThroughConcatenationBenchmark":
49,416 ±(99.9%) 0,435 ns/op [Average]
(min, avg, max) = (48,426, 49,416, 51,057), stdev = 0,651
CI (99.9%): [48,981, 49,851] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 1.8.0_161, VM 25.161-b12
# VM invoker: C:\Program Files\Java\jre1.8.0_161\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.OrdinalStringFormatBenchmark.formatThroughMessageFormatBenchmark
# Run progress: 50,00% complete, ETA 00:02:17
# Fork: 1 of 3
# Warmup Iteration 1: 1469,943 ns/op
# Warmup Iteration 2: 1297,225 ns/op
# Warmup Iteration 3: 1118,280 ns/op
# Warmup Iteration 4: 1008,395 ns/op
# Warmup Iteration 5: 1010,427 ns/op
Iteration 1: 1045,570 ns/op
Iteration 2: 1055,899 ns/op
Iteration 3: 1032,176 ns/op
Iteration 4: 1033,352 ns/op
Iteration 5: 1024,963 ns/op
Iteration 6: 1029,085 ns/op
Iteration 7: 1022,343 ns/op
Iteration 8: 1012,589 ns/op
Iteration 9: 1026,919 ns/op
Iteration 10: 1015,923 ns/op
# Run progress: 58,33% complete, ETA 00:01:54
# Fork: 2 of 3
# Warmup Iteration 1: 1466,094 ns/op
# Warmup Iteration 2: 1164,720 ns/op
# Warmup Iteration 3: 1093,806 ns/op
# Warmup Iteration 4: 999,967 ns/op
# Warmup Iteration 5: 1010,377 ns/op
Iteration 1: 1011,633 ns/op
Iteration 2: 999,827 ns/op
Iteration 3: 1005,580 ns/op
Iteration 4: 1012,595 ns/op
Iteration 5: 1007,700 ns/op
Iteration 6: 1012,898 ns/op
Iteration 7: 1034,821 ns/op
Iteration 8: 1003,250 ns/op
Iteration 9: 1011,014 ns/op
Iteration 10: 1006,375 ns/op
# Run progress: 66,67% complete, ETA 00:01:31
# Fork: 3 of 3
# Warmup Iteration 1: 1572,302 ns/op
# Warmup Iteration 2: 1494,790 ns/op
# Warmup Iteration 3: 1214,017 ns/op
# Warmup Iteration 4: 1057,334 ns/op
# Warmup Iteration 5: 1099,289 ns/op
Iteration 1: 987,605 ns/op
Iteration 2: 990,904 ns/op
Iteration 3: 991,050 ns/op
Iteration 4: 1000,703 ns/op
Iteration 5: 1056,985 ns/op
Iteration 6: 1028,472 ns/op
Iteration 7: 1058,749 ns/op
Iteration 8: 1003,892 ns/op
Iteration 9: 1009,049 ns/op
Iteration 10: 1008,405 ns/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.OrdinalStringFormatBenchmark.formatThroughMessageFormatBenchmark":
1018,011 ±(99.9%) 12,805 ns/op [Average]
(min, avg, max) = (987,605, 1018,011, 1058,749), stdev = 19,165
CI (99.9%): [1005,206, 1030,815] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 1.8.0_161, VM 25.161-b12
# VM invoker: C:\Program Files\Java\jre1.8.0_161\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.OrdinalStringFormatBenchmark.formatThroughPatternBenchmark
# Run progress: 75,00% complete, ETA 00:01:08
# Fork: 1 of 3
# Warmup Iteration 1: 2070,487 ns/op
# Warmup Iteration 2: 1660,717 ns/op
# Warmup Iteration 3: 1619,241 ns/op
# Warmup Iteration 4: 1494,624 ns/op
# Warmup Iteration 5: 1554,734 ns/op
Iteration 1: 1516,562 ns/op
Iteration 2: 1503,105 ns/op
Iteration 3: 1501,292 ns/op
Iteration 4: 1501,102 ns/op
Iteration 5: 1487,718 ns/op
Iteration 6: 1486,100 ns/op
Iteration 7: 1496,293 ns/op
Iteration 8: 1543,699 ns/op
Iteration 9: 1564,870 ns/op
Iteration 10: 1645,359 ns/op
# Run progress: 83,33% complete, ETA 00:00:45
# Fork: 2 of 3
# Warmup Iteration 1: 2398,095 ns/op
# Warmup Iteration 2: 1813,653 ns/op
# Warmup Iteration 3: 1597,230 ns/op
# Warmup Iteration 4: 1564,952 ns/op
# Warmup Iteration 5: 1503,908 ns/op
Iteration 1: 1507,203 ns/op
Iteration 2: 1489,109 ns/op
Iteration 3: 1484,389 ns/op
Iteration 4: 1490,826 ns/op
Iteration 5: 1487,540 ns/op
Iteration 6: 1503,939 ns/op
Iteration 7: 1511,837 ns/op
Iteration 8: 1506,471 ns/op
Iteration 9: 1502,044 ns/op
Iteration 10: 1514,643 ns/op
# Run progress: 91,67% complete, ETA 00:00:22
# Fork: 3 of 3
# Warmup Iteration 1: 2069,954 ns/op
# Warmup Iteration 2: 1857,799 ns/op
# Warmup Iteration 3: 1664,149 ns/op
# Warmup Iteration 4: 1586,673 ns/op
# Warmup Iteration 5: 1500,493 ns/op
Iteration 1: 1475,253 ns/op
Iteration 2: 1472,748 ns/op
Iteration 3: 1492,754 ns/op
Iteration 4: 1509,337 ns/op
Iteration 5: 1490,256 ns/op
Iteration 6: 1487,948 ns/op
Iteration 7: 1507,194 ns/op
Iteration 8: 1487,571 ns/op
Iteration 9: 1486,298 ns/op
Iteration 10: 1536,766 ns/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.OrdinalStringFormatBenchmark.formatThroughPatternBenchmark":
1506,341 ±(99.9%) 21,927 ns/op [Average]
(min, avg, max) = (1472,748, 1506,341, 1645,359), stdev = 32,819
CI (99.9%): [1484,414, 1528,268] (assumes normal distribution)
# Run complete. Total time: 00:04:35
Benchmark Mode Cnt Score Error Units
OrdinalStringFormatBenchmark.formatThroughBuilderBenchmark avgt 30 50,719 ± 1,139 ns/op
OrdinalStringFormatBenchmark.formatThroughConcatenationBenchmark avgt 30 49,416 ± 0,435 ns/op
OrdinalStringFormatBenchmark.formatThroughMessageFormatBenchmark avgt 30 1018,011 ± 12,805 ns/op
OrdinalStringFormatBenchmark.formatThroughPatternBenchmark avgt 30 1506,341 ± 21,927 ns/op
Что вообще произошло?
1.
String.format() ожидаемо оказался самым медленным результатом — это и применение регулярок, и создание вспомогательных объектов, и множество валидаций строки шаблона и аргументов. Если сравнивать с MessageFormat.format(), который у нас вне конкурса, то по наблюдениям на разных шаблонах можно получить разные результаты — в каких-то случаях быстрее один способ, в каких-то другой. В нашем случае MessageFormat.format() оказался быстрее. При этом его результат можно было ещё существенно ускорить, если переиспользовать объект MessageFormat повторно, — в этом случае будут сэкономлены ресурсы на парсинг шаблона.2. Использование
StringBuilder и обычной конкатенации дали одинаковый результат. Чуть большее время бенчмарка со StringBuilder — Ещё один бенчмарк и подтверждение мифа?
Позволю себе ещё один бенчмарк. Будем форматировать строки в том виде, в каком их просит Graphite (средство для сбора метрик):
<метрика> <значение> <timestamp>
Код форматирования
package ru.gnkoshelev.jbreak2018.perf_tests.strings;
import java.text.MessageFormat;
/**
* Created by kgn on 18.03.2018.
*/
public class MetricsFormat {
public static String formatThroughPattern(String metrics, int value, long timestamp) {
return String.format(
"%s %d %d",
metrics, value, timestamp);
}
public static String formatThroughConcatenation(String metrics, int value, long timestamp) {
return metrics + " " + value + " " + timestamp;
}
public static String formatThroughBuilder(String metrics, int value, long timestamp) {
return new StringBuilder(metrics)
.append(" ")
.append(value)
.append(" ")
.append(timestamp)
.toString();
}
public static String formatThroughMessageFormat(String metrics, int value, long timestamp) {
return MessageFormat.format(
"{0} {1} {2}",
metrics, String.valueOf(value), String.valueOf(timestamp));
}
}
И кусок бенчмарка (полный код всех бенчмарков доступен на github):
@Fork(value = 3, warmups = 0)
@Warmup(iterations = 5, time = 1_500, timeUnit = TimeUnit.MILLISECONDS)
@Measurement(iterations = 10, time = 1_500, timeUnit = TimeUnit.MILLISECONDS)
@OutputTimeUnit(value = TimeUnit.NANOSECONDS)
@BenchmarkMode(Mode.AverageTime)
@State(Scope.Benchmark)
public class MetricsFormatBenchmark {
public String metrics;
public int value;
public long timestamp;
@Setup
public void setup() {
metrics = "my-awesome-project"
+ ".my-awesome-microservice-of-my-awesome-project"
+ ".my-host-for-my-awesome-microservice-of-my-awesome-project"
+ ".my-custom-metric-from-my-host-of-my-awesome-microservice-of-my-awesome-project"
+ ".p99-for-my-custom-metric-of-my-awesome-microservice-of-my-awesome-project";
value = 1;
timestamp = 1521331200000L;
}
@Benchmark
public void formatThroughPatternBenchmark(Blackhole bh) {
bh.consume(formatThroughPattern(metrics, value, timestamp));
}
@Benchmark
public void formatThroughConcatenationBenchmark(Blackhole bh) {
bh.consume(formatThroughConcatenation(metrics, value, timestamp));
}
@Benchmark
public void formatThroughBuilderBenchmark(Blackhole bh) {
bh.consume(formatThroughBuilder(metrics, value, timestamp));
}
@Benchmark
public void formatThroughMessageFormatBuilder(Blackhole bh) {
bh.consume(formatThroughMessageFormat(metrics, value, timestamp));
}
}
Результаты бенчмарка:
Benchmark Mode Cnt Score Error Units
...formatThroughBuilderBenchmark avgt 30 212,410 ± 2,383 ns/op
...formatThroughConcatenationBenchmark avgt 30 340,894 ± 1,759 ns/op
...formatThroughMessageFormatBuilder avgt 30 747,888 ± 16,856 ns/op
...formatThroughPatternBenchmark avgt 30 1432,906 ± 10,302 ns/op
Результаты бенчмарка целиком
# JMH version: 1.20
# VM version: JDK 1.8.0_161, VM 25.161-b12
# VM invoker: C:\Program Files\Java\jre1.8.0_161\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughBuilderBenchmark
# Run progress: 0,00% complete, ETA 00:04:30
# Fork: 1 of 3
# Warmup Iteration 1: 364,237 ns/op
# Warmup Iteration 2: 225,585 ns/op
# Warmup Iteration 3: 214,730 ns/op
# Warmup Iteration 4: 208,999 ns/op
# Warmup Iteration 5: 209,362 ns/op
Iteration 1: 211,761 ns/op
Iteration 2: 210,992 ns/op
Iteration 3: 210,520 ns/op
Iteration 4: 210,215 ns/op
Iteration 5: 210,570 ns/op
Iteration 6: 211,235 ns/op
Iteration 7: 211,023 ns/op
Iteration 8: 210,616 ns/op
Iteration 9: 222,262 ns/op
Iteration 10: 224,458 ns/op
# Run progress: 8,33% complete, ETA 00:04:12
# Fork: 2 of 3
# Warmup Iteration 1: 318,609 ns/op
# Warmup Iteration 2: 206,168 ns/op
# Warmup Iteration 3: 206,740 ns/op
# Warmup Iteration 4: 210,160 ns/op
# Warmup Iteration 5: 210,540 ns/op
Iteration 1: 208,689 ns/op
Iteration 2: 209,858 ns/op
Iteration 3: 210,219 ns/op
Iteration 4: 208,769 ns/op
Iteration 5: 211,801 ns/op
Iteration 6: 208,374 ns/op
Iteration 7: 211,621 ns/op
Iteration 8: 210,325 ns/op
Iteration 9: 212,575 ns/op
Iteration 10: 213,103 ns/op
# Run progress: 16,67% complete, ETA 00:03:49
# Fork: 3 of 3
# Warmup Iteration 1: 278,328 ns/op
# Warmup Iteration 2: 205,199 ns/op
# Warmup Iteration 3: 211,429 ns/op
# Warmup Iteration 4: 212,721 ns/op
# Warmup Iteration 5: 216,514 ns/op
Iteration 1: 210,979 ns/op
Iteration 2: 214,867 ns/op
Iteration 3: 211,800 ns/op
Iteration 4: 217,169 ns/op
Iteration 5: 212,202 ns/op
Iteration 6: 210,910 ns/op
Iteration 7: 212,878 ns/op
Iteration 8: 215,043 ns/op
Iteration 9: 214,553 ns/op
Iteration 10: 212,912 ns/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughBuilderBenchmark":
212,410 ±(99.9%) 2,383 ns/op [Average]
(min, avg, max) = (208,374, 212,410, 224,458), stdev = 3,566
CI (99.9%): [210,027, 214,793] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 1.8.0_161, VM 25.161-b12
# VM invoker: C:\Program Files\Java\jre1.8.0_161\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughConcatenationBenchmark
# Run progress: 25,00% complete, ETA 00:03:26
# Fork: 1 of 3
# Warmup Iteration 1: 461,604 ns/op
# Warmup Iteration 2: 338,344 ns/op
# Warmup Iteration 3: 339,651 ns/op
# Warmup Iteration 4: 341,987 ns/op
# Warmup Iteration 5: 341,775 ns/op
Iteration 1: 340,811 ns/op
Iteration 2: 340,931 ns/op
Iteration 3: 341,112 ns/op
Iteration 4: 341,395 ns/op
Iteration 5: 338,871 ns/op
Iteration 6: 337,875 ns/op
Iteration 7: 346,943 ns/op
Iteration 8: 339,328 ns/op
Iteration 9: 335,932 ns/op
Iteration 10: 338,702 ns/op
# Run progress: 33,33% complete, ETA 00:03:03
# Fork: 2 of 3
# Warmup Iteration 1: 470,278 ns/op
# Warmup Iteration 2: 334,495 ns/op
# Warmup Iteration 3: 336,727 ns/op
# Warmup Iteration 4: 339,971 ns/op
# Warmup Iteration 5: 339,774 ns/op
Iteration 1: 339,405 ns/op
Iteration 2: 339,588 ns/op
Iteration 3: 340,777 ns/op
Iteration 4: 345,855 ns/op
Iteration 5: 342,180 ns/op
Iteration 6: 337,955 ns/op
Iteration 7: 345,554 ns/op
Iteration 8: 337,636 ns/op
Iteration 9: 345,226 ns/op
Iteration 10: 339,453 ns/op
# Run progress: 41,67% complete, ETA 00:02:40
# Fork: 3 of 3
# Warmup Iteration 1: 473,061 ns/op
# Warmup Iteration 2: 334,747 ns/op
# Warmup Iteration 3: 340,089 ns/op
# Warmup Iteration 4: 334,962 ns/op
# Warmup Iteration 5: 334,361 ns/op
Iteration 1: 338,737 ns/op
Iteration 2: 338,276 ns/op
Iteration 3: 340,775 ns/op
Iteration 4: 341,302 ns/op
Iteration 5: 342,850 ns/op
Iteration 6: 341,880 ns/op
Iteration 7: 342,687 ns/op
Iteration 8: 343,406 ns/op
Iteration 9: 341,336 ns/op
Iteration 10: 340,047 ns/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughConcatenationBenchmark":
340,894 ±(99.9%) 1,759 ns/op [Average]
(min, avg, max) = (335,932, 340,894, 346,943), stdev = 2,632
CI (99.9%): [339,136, 342,653] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 1.8.0_161, VM 25.161-b12
# VM invoker: C:\Program Files\Java\jre1.8.0_161\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughMessageFormatBuilder
# Run progress: 50,00% complete, ETA 00:02:17
# Fork: 1 of 3
# Warmup Iteration 1: 1174,256 ns/op
# Warmup Iteration 2: 955,340 ns/op
# Warmup Iteration 3: 833,853 ns/op
# Warmup Iteration 4: 743,211 ns/op
# Warmup Iteration 5: 749,805 ns/op
Iteration 1: 736,922 ns/op
Iteration 2: 739,920 ns/op
Iteration 3: 745,799 ns/op
Iteration 4: 749,026 ns/op
Iteration 5: 753,321 ns/op
Iteration 6: 756,947 ns/op
Iteration 7: 748,437 ns/op
Iteration 8: 745,221 ns/op
Iteration 9: 743,668 ns/op
Iteration 10: 749,899 ns/op
# Run progress: 58,33% complete, ETA 00:01:54
# Fork: 2 of 3
# Warmup Iteration 1: 1093,949 ns/op
# Warmup Iteration 2: 904,903 ns/op
# Warmup Iteration 3: 888,462 ns/op
# Warmup Iteration 4: 756,249 ns/op
# Warmup Iteration 5: 842,296 ns/op
Iteration 1: 729,334 ns/op
Iteration 2: 797,580 ns/op
Iteration 3: 736,540 ns/op
Iteration 4: 741,176 ns/op
Iteration 5: 731,403 ns/op
Iteration 6: 732,560 ns/op
Iteration 7: 767,631 ns/op
Iteration 8: 731,333 ns/op
Iteration 9: 731,261 ns/op
Iteration 10: 753,285 ns/op
# Run progress: 66,67% complete, ETA 00:01:31
# Fork: 3 of 3
# Warmup Iteration 1: 1156,247 ns/op
# Warmup Iteration 2: 1031,444 ns/op
# Warmup Iteration 3: 849,080 ns/op
# Warmup Iteration 4: 730,123 ns/op
# Warmup Iteration 5: 724,077 ns/op
Iteration 1: 729,569 ns/op
Iteration 2: 781,161 ns/op
Iteration 3: 716,803 ns/op
Iteration 4: 724,149 ns/op
Iteration 5: 818,748 ns/op
Iteration 6: 815,800 ns/op
Iteration 7: 728,733 ns/op
Iteration 8: 727,143 ns/op
Iteration 9: 734,503 ns/op
Iteration 10: 738,770 ns/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughMessageFormatBuilder":
747,888 ±(99.9%) 16,856 ns/op [Average]
(min, avg, max) = (716,803, 747,888, 818,748), stdev = 25,229
CI (99.9%): [731,032, 764,744] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 1.8.0_161, VM 25.161-b12
# VM invoker: C:\Program Files\Java\jre1.8.0_161\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughPatternBenchmark
# Run progress: 75,00% complete, ETA 00:01:08
# Fork: 1 of 3
# Warmup Iteration 1: 2117,334 ns/op
# Warmup Iteration 2: 1622,235 ns/op
# Warmup Iteration 3: 1431,764 ns/op
# Warmup Iteration 4: 1431,065 ns/op
# Warmup Iteration 5: 1438,533 ns/op
Iteration 1: 1420,598 ns/op
Iteration 2: 1492,345 ns/op
Iteration 3: 1419,019 ns/op
Iteration 4: 1425,040 ns/op
Iteration 5: 1423,276 ns/op
Iteration 6: 1428,505 ns/op
Iteration 7: 1435,056 ns/op
Iteration 8: 1432,752 ns/op
Iteration 9: 1427,263 ns/op
Iteration 10: 1436,453 ns/op
# Run progress: 83,33% complete, ETA 00:00:45
# Fork: 2 of 3
# Warmup Iteration 1: 2111,790 ns/op
# Warmup Iteration 2: 1603,000 ns/op
# Warmup Iteration 3: 1427,974 ns/op
# Warmup Iteration 4: 1437,411 ns/op
# Warmup Iteration 5: 1438,924 ns/op
Iteration 1: 1423,295 ns/op
Iteration 2: 1429,621 ns/op
Iteration 3: 1428,471 ns/op
Iteration 4: 1434,627 ns/op
Iteration 5: 1439,802 ns/op
Iteration 6: 1441,290 ns/op
Iteration 7: 1438,296 ns/op
Iteration 8: 1441,198 ns/op
Iteration 9: 1456,831 ns/op
Iteration 10: 1443,969 ns/op
# Run progress: 91,67% complete, ETA 00:00:22
# Fork: 3 of 3
# Warmup Iteration 1: 2149,129 ns/op
# Warmup Iteration 2: 1608,200 ns/op
# Warmup Iteration 3: 1406,910 ns/op
# Warmup Iteration 4: 1413,134 ns/op
# Warmup Iteration 5: 1413,094 ns/op
Iteration 1: 1409,053 ns/op
Iteration 2: 1417,015 ns/op
Iteration 3: 1423,907 ns/op
Iteration 4: 1419,448 ns/op
Iteration 5: 1425,128 ns/op
Iteration 6: 1425,369 ns/op
Iteration 7: 1428,064 ns/op
Iteration 8: 1432,042 ns/op
Iteration 9: 1433,438 ns/op
Iteration 10: 1455,998 ns/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughPatternBenchmark":
1432,906 ±(99.9%) 10,302 ns/op [Average]
(min, avg, max) = (1409,053, 1432,906, 1492,345), stdev = 15,420
CI (99.9%): [1422,604, 1443,208] (assumes normal distribution)
# Run complete. Total time: 00:04:35
Benchmark Mode Cnt Score Error Units
MetricsFormatBenchmark.formatThroughBuilderBenchmark avgt 30 212,410 ± 2,383 ns/op
MetricsFormatBenchmark.formatThroughConcatenationBenchmark avgt 30 340,894 ± 1,759 ns/op
MetricsFormatBenchmark.formatThroughMessageFormatBuilder avgt 30 747,888 ± 16,856 ns/op
MetricsFormatBenchmark.formatThroughPatternBenchmark avgt 30 1432,906 ± 10,302 ns/op
Что вообще произошло?
1.
String.format() и MessageFormat.format() нам не так интересны.2. Результат
StringBuilder оказался лучше примерно в 1.5 раза. И тут уже не до случайностей.Глубже в байткод, дальше в исходники
Чтобы разобраться в происходящем, глянем на байткод, который получился в результате компиляции наших методов в
MetricsFormat: public static java.lang.String formatThroughConcatenation(java.lang.String, int, long);
Code:
0: new #7 // class java/lang/StringBuilder
3: dup
4: invokespecial #8 // Method java/lang/StringBuilder."<init>":()V
7: aload_0
8: invokevirtual #9 // Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder;
11: ldc #10 // String
13: invokevirtual #9 // Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder;
16: iload_1
17: invokevirtual #11 // Method java/lang/StringBuilder.append:(I)Ljava/lang/StringBuilder;
20: ldc #10 // String
22: invokevirtual #9 // Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder;
25: lload_2
26: invokevirtual #12 // Method java/lang/StringBuilder.append:(J)Ljava/lang/StringBuilder;
29: invokevirtual #13 // Method java/lang/StringBuilder.toString:()Ljava/lang/String;
32: areturn
public static java.lang.String formatThroughBuilder(java.lang.String, int, long);
Code:
0: new #7 // class java/lang/StringBuilder
3: dup
4: aload_0
5: invokespecial #14 // Method java/lang/StringBuilder."<init>":(Ljava/lang/String;)V
8: ldc #10 // String
10: invokevirtual #9 // Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder;
13: iload_1
14: invokevirtual #11 // Method java/lang/StringBuilder.append:(I)Ljava/lang/StringBuilder;
17: ldc #10 // String
19: invokevirtual #9 // Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder;
22: lload_2
23: invokevirtual #12 // Method java/lang/StringBuilder.append:(J)Ljava/lang/StringBuilder;
26: invokevirtual #13 // Method java/lang/StringBuilder.toString:()Ljava/lang/String;
29: areturn
Разберём в деталях, что мы видим:
- В методе, где была конкатенация строк, сейчас создание объекта
StringBuilder. - Тела методов очень похожи, но отличаются способом создания
StringBuilder— в случае самописного использованияStringBuilderвызывается конструктор, принимающий строку на вход, а в варианте с конкатенациейStringBuilderсоздаётся путём вызова пустого конструктора. - В результате создания пустого
StringBuilderтребуется дополнительный вызовStringBuilder.append().
Как так получилось, что один единственный дополнительный вызов
StringBuilder.append() привёл к снижению производительности?Посмотрим на конструкторы:
public StringBuilder() {
super(16);
}
public StringBuilder(String str) {
super(str.length() + 16);
append(str);
}
Оказывается, что и append-то никуда не делся — он вызывается внутри конструктора. Тем не менее, ответ кроется в этом участке кода, а именно в числе 16: авторы
StringBuilder предусмотрительно выделили дополнительное место под 16 символов в буфере при создании объекта.Когда мы создали
StringBuilder и положили в него первую строку metrics, передав её в конструкторе, у нас ещё оставалось 16 символов в запасе, прежде чем нужно будет расширить буфер (массив символов AbstractStringBuilder.value). По случайному совпадению два пробела, число 1 и значение timestamp уложились ровно в 16 символов.С другой стороны, созданный пустым
StringBuilder оказался не готов вместить в себя строку metrics и буфер был пересоздан. Но и тут всё оказывается не так просто.Интересующий нас кусок кода
AbstractStringBuilder: public AbstractStringBuilder append(String str) {
if (str == null)
return appendNull();
int len = str.length();
ensureCapacityInternal(count + len);
str.getChars(0, len, value, count);
count += len;
return this;
}
private void ensureCapacityInternal(int minimumCapacity) {
// overflow-conscious code
if (minimumCapacity - value.length > 0) {
value = Arrays.copyOf(value,
newCapacity(minimumCapacity));
}
}
private int newCapacity(int minCapacity) {
// overflow-conscious code
int newCapacity = (value.length << 1) + 2;
if (newCapacity - minCapacity < 0) {
newCapacity = minCapacity;
}
return (newCapacity <= 0 || MAX_ARRAY_SIZE - newCapacity < 0)
? hugeCapacity(minCapacity)
: newCapacity;
}
Когда в
StringBuilder не хватает места при очередном append, осуществляется попытка создать буфер вдвое больший, чем был ранее (length * 2 + 2 если быть точнее).Если не удаётся (когда в двойной буфер добавляемая строка по-прежнему не помещается, что у нас и произошло при добавлении идентификатора метрики metrics), то создаётся буфер, длина которого равна
count + len, где count — уже занятое место в буфере, а len — длина добавляемой строки. В примере с нашей метрикой count == 0, а len == 275.Таким образом, первый вызов
StringBuilder.append() привёл к созданию нового массива символов с длиной 275.Второй вызов также привёл к повторному созданию массива, так как идентификатор метрики полностью занимал весь буфер. Кроме того, что размер буфера стал равен
275 * 2 + 2 = 552, так ещё потребовалось копирование 275 символов из старого буфера. И тут уже никакой JIT не помог.Правильный ответ на задачу
Вариант 1 самый медленный, а 2 и 3 дают одинаковый результат.
В нашем примере для обоих вариантов 2 и 3 HotSpot применил оптимизацию
OptimizeStringConcat, заменив вызов Java-кода на использование intrinsic-методов. Если отключить оптимизацию -XX:-OptimizeStringConcat, то получим следующие результаты:Benchmark Mode Cnt Score Error Units
Ordinal...BuilderBenchmark avgt 30 126,876 ± 5,962 ns/op
Ordinal...ConcatenationBenchmark avgt 30 186,758 ± 11,158 ns/op
Ordinal...MessageFormatBenchmark avgt 30 1157,645 ± 34,743 ns/op
Ordinal...PatternBenchmark avgt 30 1756,613 ± 131,212 ns/opНиже ещё будет про особенность работы
OptimizeStringConcat.Статистика
Эта задача была самой простой из предложенных — её правильно решили 10 человек из 32 и ещё 18 участников конференции дали частично правильный ответ.
Частично правильный ответ заключался в том, что, например, методы расставлены правильно, но пояснения к ответу никакого дано не было, либо оно было верно только от части.
Самый распространённый ответ по 2 и 3 — javac выдаёт одинаковый байткод. Несмотря на то, что это не совсем так, как мы выяснили выше — данный ответ засчитывался как правильный.
Интересные факты
В одном из пояснений было верно подмечено, что компиляция конкатенации в StringBuilder не специфицирована. В разделе 15.18.1 спецификации упоминается следующее:
An implementation may choose to perform conversion and concatenation in one step to avoid creating and then discarding an intermediate String object. To increase the performance of repeated string concatenation, a Java compiler may use the StringBuffer class or a similar technique to reduce the number of intermediate String objects that are created by evaluation of an expression.
Интересно, что в спецификации к Java 8 говорится о
StringBuffer, тогда как с Java 1.5 (когда появился StringBuilder) код конкатенации компилируется в StringBuilder. При этом в Java 1.4 код метода formatThroughConcatenation компилируется в байткод, единственным отличием которого является использование StringBuffer вместо StringBuilder.Байткод в результате компиляции в Java 1.4
public java.lang.String formatThroughConcatenation(java.lang.String, java.lang.String, java.lang.String, java.lang.String);
Code:
0: new #2; //class java/lang/StringBuffer
3: dup
4: invokespecial #3; //Method java/lang/StringBuffer."<init>":()V
7: ldc #4; //String Он,
9: invokevirtual #5; //Method java/lang/StringBuffer.append:(Ljava/lang/String;)Ljava/lang/StringBuffer;
12: aload_1
13: invokevirtual #5; //Method java/lang/StringBuffer.append:(Ljava/lang/String;)Ljava/lang/StringBuffer;
16: ldc #6; //String , придумал такие
18: invokevirtual #5; //Method java/lang/StringBuffer.append:(Ljava/lang/String;)Ljava/lang/StringBuffer;
21: aload_2
22: invokevirtual #5; //Method java/lang/StringBuffer.append:(Ljava/lang/String;)Ljava/lang/StringBuffer;
25: ldc #7; //String задачи. Приду на стенд
27: invokevirtual #5; //Method java/lang/StringBuffer.append:(Ljava/lang/String;)Ljava/lang/StringBuffer;
30: aload_3
31: invokevirtual #5; //Method java/lang/StringBuffer.append:(Ljava/lang/String;)Ljava/lang/StringBuffer;
34: ldc #8; //String и скажу ему
36: invokevirtual #5; //Method java/lang/StringBuffer.append:(Ljava/lang/String;)Ljava/lang/StringBuffer;
39: aload 4
41: invokevirtual #5; //Method java/lang/StringBuffer.append:(Ljava/lang/String;)Ljava/lang/StringBuffer;
44: invokevirtual #9; //Method java/lang/StringBuffer.toString:()Ljava/lang/String;
47: areturn
Раз уж мы заговорили про другие версии Java, то не лишним будет попробовать собрать и прогнать бенчмарк с использованием Java 9 (JRE 9.0.4).
Benchmark Mode Cnt Score Error Units
Metrics...BuilderBenchmark avgt 30 207,168 ± 4,245 ns/op
Metrics...ConcatenationBenchmark avgt 30 56,220 ± 1,051 ns/op
Metrics...MessageFormatBuilder avgt 30 594,952 ± 19,025 ns/op
Metrics...PatternBenchmark avgt 30 1131,698 ± 14,363 ns/op
Ordinal...BuilderBenchmark avgt 30 53,221 ± 1,691 ns/op
Ordinal...ConcatenationBenchmark avgt 30 68,486 ± 1,936 ns/op
Ordinal...MessageFormatBenchmark avgt 30 1207,907 ± 19,414 ns/op
Ordinal...PatternBenchmark avgt 30 1972,689 ± 33,432 ns/op
Результаты бенчмарка целиком
# JMH version: 1.20
# VM version: JDK 9.0.4, VM 9.0.4+11
# VM invoker: C:\Program Files\Java\jre-9.0.4\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.builderBenchmark
# Parameters: (N = 10)
# Run progress: 0,00% complete, ETA 00:18:00
# Fork: 1 of 3
# Warmup Iteration 1: 0,179 us/op
# Warmup Iteration 2: 0,155 us/op
# Warmup Iteration 3: 0,154 us/op
# Warmup Iteration 4: 0,154 us/op
# Warmup Iteration 5: 0,154 us/op
Iteration 1: 0,154 us/op
Iteration 2: 0,155 us/op
Iteration 3: 0,155 us/op
Iteration 4: 0,154 us/op
Iteration 5: 0,153 us/op
Iteration 6: 0,156 us/op
Iteration 7: 0,168 us/op
Iteration 8: 0,157 us/op
Iteration 9: 0,159 us/op
Iteration 10: 0,156 us/op
# Run progress: 2,08% complete, ETA 00:17:58
# Fork: 2 of 3
# Warmup Iteration 1: 0,182 us/op
# Warmup Iteration 2: 0,160 us/op
# Warmup Iteration 3: 0,154 us/op
# Warmup Iteration 4: 0,162 us/op
# Warmup Iteration 5: 0,155 us/op
Iteration 1: 0,157 us/op
Iteration 2: 0,159 us/op
Iteration 3: 0,154 us/op
Iteration 4: 0,155 us/op
Iteration 5: 0,164 us/op
Iteration 6: 0,155 us/op
Iteration 7: 0,156 us/op
Iteration 8: 0,155 us/op
Iteration 9: 0,169 us/op
Iteration 10: 0,171 us/op
# Run progress: 4,17% complete, ETA 00:17:34
# Fork: 3 of 3
# Warmup Iteration 1: 0,229 us/op
# Warmup Iteration 2: 0,218 us/op
# Warmup Iteration 3: 0,190 us/op
# Warmup Iteration 4: 0,191 us/op
# Warmup Iteration 5: 0,180 us/op
Iteration 1: 0,173 us/op
Iteration 2: 0,168 us/op
Iteration 3: 0,167 us/op
Iteration 4: 0,168 us/op
Iteration 5: 0,161 us/op
Iteration 6: 0,156 us/op
Iteration 7: 0,155 us/op
Iteration 8: 0,156 us/op
Iteration 9: 0,163 us/op
Iteration 10: 0,161 us/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.builderBenchmark":
0,160 ±(99.9%) 0,004 us/op [Average]
(min, avg, max) = (0,153, 0,160, 0,173), stdev = 0,006
CI (99.9%): [0,156, 0,164] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 9.0.4, VM 9.0.4+11
# VM invoker: C:\Program Files\Java\jre-9.0.4\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.builderBenchmark
# Parameters: (N = 100)
# Run progress: 6,25% complete, ETA 00:17:12
# Fork: 1 of 3
# Warmup Iteration 1: 1,487 us/op
# Warmup Iteration 2: 1,376 us/op
# Warmup Iteration 3: 1,328 us/op
# Warmup Iteration 4: 1,327 us/op
# Warmup Iteration 5: 1,447 us/op
Iteration 1: 1,334 us/op
Iteration 2: 1,353 us/op
Iteration 3: 1,412 us/op
Iteration 4: 1,427 us/op
Iteration 5: 1,793 us/op
Iteration 6: 1,523 us/op
Iteration 7: 1,411 us/op
Iteration 8: 1,468 us/op
Iteration 9: 1,390 us/op
Iteration 10: 1,348 us/op
# Run progress: 8,33% complete, ETA 00:16:49
# Fork: 2 of 3
# Warmup Iteration 1: 1,483 us/op
# Warmup Iteration 2: 1,645 us/op
# Warmup Iteration 3: 1,499 us/op
# Warmup Iteration 4: 1,550 us/op
# Warmup Iteration 5: 1,527 us/op
Iteration 1: 1,591 us/op
Iteration 2: 1,596 us/op
Iteration 3: 1,668 us/op
Iteration 4: 1,784 us/op
Iteration 5: 1,733 us/op
Iteration 6: 1,498 us/op
Iteration 7: 1,532 us/op
Iteration 8: 1,566 us/op
Iteration 9: 1,524 us/op
Iteration 10: 1,334 us/op
# Run progress: 10,42% complete, ETA 00:16:26
# Fork: 3 of 3
# Warmup Iteration 1: 1,504 us/op
# Warmup Iteration 2: 1,314 us/op
# Warmup Iteration 3: 1,285 us/op
# Warmup Iteration 4: 1,290 us/op
# Warmup Iteration 5: 1,284 us/op
Iteration 1: 1,283 us/op
Iteration 2: 1,288 us/op
Iteration 3: 1,287 us/op
Iteration 4: 1,291 us/op
Iteration 5: 1,282 us/op
Iteration 6: 1,286 us/op
Iteration 7: 1,297 us/op
Iteration 8: 1,286 us/op
Iteration 9: 1,284 us/op
Iteration 10: 1,285 us/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.builderBenchmark":
1,438 ±(99.9%) 0,107 us/op [Average]
(min, avg, max) = (1,282, 1,438, 1,793), stdev = 0,160
CI (99.9%): [1,331, 1,546] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 9.0.4, VM 9.0.4+11
# VM invoker: C:\Program Files\Java\jre-9.0.4\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.builderBenchmark
# Parameters: (N = 1000)
# Run progress: 12,50% complete, ETA 00:16:04
# Fork: 1 of 3
# Warmup Iteration 1: 18,564 us/op
# Warmup Iteration 2: 15,904 us/op
# Warmup Iteration 3: 15,757 us/op
# Warmup Iteration 4: 15,458 us/op
# Warmup Iteration 5: 15,754 us/op
Iteration 1: 15,474 us/op
Iteration 2: 15,388 us/op
Iteration 3: 15,454 us/op
Iteration 4: 15,434 us/op
Iteration 5: 15,462 us/op
Iteration 6: 15,437 us/op
Iteration 7: 15,355 us/op
Iteration 8: 15,509 us/op
Iteration 9: 15,415 us/op
Iteration 10: 15,367 us/op
# Run progress: 14,58% complete, ETA 00:15:41
# Fork: 2 of 3
# Warmup Iteration 1: 17,889 us/op
# Warmup Iteration 2: 15,454 us/op
# Warmup Iteration 3: 15,469 us/op
# Warmup Iteration 4: 16,110 us/op
# Warmup Iteration 5: 15,979 us/op
Iteration 1: 15,961 us/op
Iteration 2: 17,628 us/op
Iteration 3: 16,615 us/op
Iteration 4: 16,068 us/op
Iteration 5: 16,430 us/op
Iteration 6: 16,648 us/op
Iteration 7: 14,929 us/op
Iteration 8: 15,597 us/op
Iteration 9: 18,085 us/op
Iteration 10: 16,119 us/op
# Run progress: 16,67% complete, ETA 00:15:18
# Fork: 3 of 3
# Warmup Iteration 1: 20,057 us/op
# Warmup Iteration 2: 16,204 us/op
# Warmup Iteration 3: 15,858 us/op
# Warmup Iteration 4: 16,293 us/op
# Warmup Iteration 5: 15,851 us/op
Iteration 1: 17,172 us/op
Iteration 2: 16,261 us/op
Iteration 3: 15,955 us/op
Iteration 4: 15,694 us/op
Iteration 5: 15,686 us/op
Iteration 6: 15,300 us/op
Iteration 7: 16,633 us/op
Iteration 8: 16,594 us/op
Iteration 9: 15,752 us/op
Iteration 10: 15,459 us/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.builderBenchmark":
15,963 ±(99.9%) 0,493 us/op [Average]
(min, avg, max) = (14,929, 15,963, 18,085), stdev = 0,738
CI (99.9%): [15,470, 16,455] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 9.0.4, VM 9.0.4+11
# VM invoker: C:\Program Files\Java\jre-9.0.4\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.builderBenchmark
# Parameters: (N = 10000)
# Run progress: 18,75% complete, ETA 00:14:55
# Fork: 1 of 3
# Warmup Iteration 1: 193,410 us/op
# Warmup Iteration 2: 178,965 us/op
# Warmup Iteration 3: 174,831 us/op
# Warmup Iteration 4: 174,252 us/op
# Warmup Iteration 5: 172,563 us/op
Iteration 1: 175,277 us/op
Iteration 2: 175,052 us/op
Iteration 3: 170,435 us/op
Iteration 4: 172,218 us/op
Iteration 5: 169,646 us/op
Iteration 6: 174,490 us/op
Iteration 7: 170,822 us/op
Iteration 8: 167,680 us/op
Iteration 9: 172,293 us/op
Iteration 10: 169,461 us/op
# Run progress: 20,83% complete, ETA 00:14:33
# Fork: 2 of 3
# Warmup Iteration 1: 201,756 us/op
# Warmup Iteration 2: 180,306 us/op
# Warmup Iteration 3: 177,044 us/op
# Warmup Iteration 4: 176,753 us/op
# Warmup Iteration 5: 176,762 us/op
Iteration 1: 177,181 us/op
Iteration 2: 180,288 us/op
Iteration 3: 180,234 us/op
Iteration 4: 177,654 us/op
Iteration 5: 179,481 us/op
Iteration 6: 179,769 us/op
Iteration 7: 180,273 us/op
Iteration 8: 180,923 us/op
Iteration 9: 177,576 us/op
Iteration 10: 176,988 us/op
# Run progress: 22,92% complete, ETA 00:14:10
# Fork: 3 of 3
# Warmup Iteration 1: 199,773 us/op
# Warmup Iteration 2: 191,027 us/op
# Warmup Iteration 3: 175,811 us/op
# Warmup Iteration 4: 195,435 us/op
# Warmup Iteration 5: 186,448 us/op
Iteration 1: 190,321 us/op
Iteration 2: 172,248 us/op
Iteration 3: 172,875 us/op
Iteration 4: 173,850 us/op
Iteration 5: 174,142 us/op
Iteration 6: 175,412 us/op
Iteration 7: 173,791 us/op
Iteration 8: 173,810 us/op
Iteration 9: 173,287 us/op
Iteration 10: 174,731 us/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.builderBenchmark":
175,407 ±(99.9%) 3,039 us/op [Average]
(min, avg, max) = (167,680, 175,407, 190,321), stdev = 4,549
CI (99.9%): [172,368, 178,446] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 9.0.4, VM 9.0.4+11
# VM invoker: C:\Program Files\Java\jre-9.0.4\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.concatenationBenchmark
# Parameters: (N = 10)
# Run progress: 25,00% complete, ETA 00:13:47
# Fork: 1 of 3
# Warmup Iteration 1: 0,292 us/op
# Warmup Iteration 2: 0,251 us/op
# Warmup Iteration 3: 0,274 us/op
# Warmup Iteration 4: 0,268 us/op
# Warmup Iteration 5: 0,276 us/op
Iteration 1: 0,291 us/op
Iteration 2: 0,286 us/op
Iteration 3: 0,283 us/op
Iteration 4: 0,294 us/op
Iteration 5: 0,277 us/op
Iteration 6: 0,285 us/op
Iteration 7: 0,283 us/op
Iteration 8: 0,275 us/op
Iteration 9: 0,269 us/op
Iteration 10: 0,274 us/op
# Run progress: 27,08% complete, ETA 00:13:24
# Fork: 2 of 3
# Warmup Iteration 1: 0,309 us/op
# Warmup Iteration 2: 0,281 us/op
# Warmup Iteration 3: 0,292 us/op
# Warmup Iteration 4: 0,276 us/op
# Warmup Iteration 5: 0,280 us/op
Iteration 1: 0,277 us/op
Iteration 2: 0,268 us/op
Iteration 3: 0,283 us/op
Iteration 4: 0,301 us/op
Iteration 5: 0,290 us/op
Iteration 6: 0,275 us/op
Iteration 7: 0,273 us/op
Iteration 8: 0,291 us/op
Iteration 9: 0,293 us/op
Iteration 10: 0,274 us/op
# Run progress: 29,17% complete, ETA 00:13:02
# Fork: 3 of 3
# Warmup Iteration 1: 0,302 us/op
# Warmup Iteration 2: 0,257 us/op
# Warmup Iteration 3: 0,280 us/op
# Warmup Iteration 4: 0,272 us/op
# Warmup Iteration 5: 0,286 us/op
Iteration 1: 0,290 us/op
Iteration 2: 0,286 us/op
Iteration 3: 0,286 us/op
Iteration 4: 0,300 us/op
Iteration 5: 0,285 us/op
Iteration 6: 0,276 us/op
Iteration 7: 0,285 us/op
Iteration 8: 0,310 us/op
Iteration 9: 0,269 us/op
Iteration 10: 0,268 us/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.concatenationBenchmark":
0,283 ±(99.9%) 0,007 us/op [Average]
(min, avg, max) = (0,268, 0,283, 0,310), stdev = 0,010
CI (99.9%): [0,276, 0,290] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 9.0.4, VM 9.0.4+11
# VM invoker: C:\Program Files\Java\jre-9.0.4\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.concatenationBenchmark
# Parameters: (N = 100)
# Run progress: 31,25% complete, ETA 00:12:39
# Fork: 1 of 3
# Warmup Iteration 1: 10,154 us/op
# Warmup Iteration 2: 7,346 us/op
# Warmup Iteration 3: 7,357 us/op
# Warmup Iteration 4: 7,376 us/op
# Warmup Iteration 5: 7,332 us/op
Iteration 1: 7,334 us/op
Iteration 2: 7,343 us/op
Iteration 3: 7,338 us/op
Iteration 4: 7,358 us/op
Iteration 5: 7,343 us/op
Iteration 6: 7,395 us/op
Iteration 7: 7,375 us/op
Iteration 8: 7,381 us/op
Iteration 9: 7,356 us/op
Iteration 10: 7,342 us/op
# Run progress: 33,33% complete, ETA 00:12:16
# Fork: 2 of 3
# Warmup Iteration 1: 10,032 us/op
# Warmup Iteration 2: 7,326 us/op
# Warmup Iteration 3: 7,247 us/op
# Warmup Iteration 4: 7,512 us/op
# Warmup Iteration 5: 8,649 us/op
Iteration 1: 7,502 us/op
Iteration 2: 7,327 us/op
Iteration 3: 7,197 us/op
Iteration 4: 8,295 us/op
Iteration 5: 7,221 us/op
Iteration 6: 7,224 us/op
Iteration 7: 7,210 us/op
Iteration 8: 7,204 us/op
Iteration 9: 7,457 us/op
Iteration 10: 8,124 us/op
# Run progress: 35,42% complete, ETA 00:11:52
# Fork: 3 of 3
# Warmup Iteration 1: 11,735 us/op
# Warmup Iteration 2: 7,658 us/op
# Warmup Iteration 3: 7,495 us/op
# Warmup Iteration 4: 7,258 us/op
# Warmup Iteration 5: 8,326 us/op
Iteration 1: 8,001 us/op
Iteration 2: 7,964 us/op
Iteration 3: 7,854 us/op
Iteration 4: 7,480 us/op
Iteration 5: 7,556 us/op
Iteration 6: 7,928 us/op
Iteration 7: 7,335 us/op
Iteration 8: 8,161 us/op
Iteration 9: 7,989 us/op
Iteration 10: 7,372 us/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.concatenationBenchmark":
7,532 ±(99.9%) 0,220 us/op [Average]
(min, avg, max) = (7,197, 7,532, 8,295), stdev = 0,329
CI (99.9%): [7,312, 7,752] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 9.0.4, VM 9.0.4+11
# VM invoker: C:\Program Files\Java\jre-9.0.4\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.concatenationBenchmark
# Parameters: (N = 1000)
# Run progress: 37,50% complete, ETA 00:11:29
# Fork: 1 of 3
# Warmup Iteration 1: 843,574 us/op
# Warmup Iteration 2: 604,431 us/op
# Warmup Iteration 3: 602,075 us/op
# Warmup Iteration 4: 605,613 us/op
# Warmup Iteration 5: 610,006 us/op
Iteration 1: 606,927 us/op
Iteration 2: 634,940 us/op
Iteration 3: 607,559 us/op
Iteration 4: 650,631 us/op
Iteration 5: 653,789 us/op
Iteration 6: 607,988 us/op
Iteration 7: 621,988 us/op
Iteration 8: 607,247 us/op
Iteration 9: 602,864 us/op
Iteration 10: 607,888 us/op
# Run progress: 39,58% complete, ETA 00:11:06
# Fork: 2 of 3
# Warmup Iteration 1: 811,900 us/op
# Warmup Iteration 2: 603,097 us/op
# Warmup Iteration 3: 603,808 us/op
# Warmup Iteration 4: 605,518 us/op
# Warmup Iteration 5: 605,703 us/op
Iteration 1: 616,120 us/op
Iteration 2: 602,626 us/op
Iteration 3: 605,618 us/op
Iteration 4: 599,532 us/op
Iteration 5: 598,845 us/op
Iteration 6: 604,046 us/op
Iteration 7: 615,308 us/op
Iteration 8: 609,050 us/op
Iteration 9: 612,949 us/op
Iteration 10: 613,524 us/op
# Run progress: 41,67% complete, ETA 00:10:43
# Fork: 3 of 3
# Warmup Iteration 1: 852,912 us/op
# Warmup Iteration 2: 707,652 us/op
# Warmup Iteration 3: 651,288 us/op
# Warmup Iteration 4: 599,827 us/op
# Warmup Iteration 5: 621,685 us/op
Iteration 1: 598,476 us/op
Iteration 2: 601,931 us/op
Iteration 3: 602,993 us/op
Iteration 4: 602,098 us/op
Iteration 5: 623,709 us/op
Iteration 6: 615,533 us/op
Iteration 7: 623,482 us/op
Iteration 8: 591,862 us/op
Iteration 9: 624,777 us/op
Iteration 10: 595,762 us/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.concatenationBenchmark":
612,002 ±(99.9%) 9,759 us/op [Average]
(min, avg, max) = (591,862, 612,002, 653,789), stdev = 14,606
CI (99.9%): [602,244, 621,761] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 9.0.4, VM 9.0.4+11
# VM invoker: C:\Program Files\Java\jre-9.0.4\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.concatenationBenchmark
# Parameters: (N = 10000)
# Run progress: 43,75% complete, ETA 00:10:20
# Fork: 1 of 3
# Warmup Iteration 1: 85359,249 us/op
# Warmup Iteration 2: 60094,054 us/op
# Warmup Iteration 3: 58604,795 us/op
# Warmup Iteration 4: 63162,713 us/op
# Warmup Iteration 5: 61908,459 us/op
Iteration 1: 58603,106 us/op
Iteration 2: 59940,727 us/op
Iteration 3: 58251,292 us/op
Iteration 4: 58429,386 us/op
Iteration 5: 58252,382 us/op
Iteration 6: 58310,251 us/op
Iteration 7: 59034,690 us/op
Iteration 8: 58480,766 us/op
Iteration 9: 58441,828 us/op
Iteration 10: 58242,481 us/op
# Run progress: 45,83% complete, ETA 00:09:58
# Fork: 2 of 3
# Warmup Iteration 1: 85157,562 us/op
# Warmup Iteration 2: 58764,257 us/op
# Warmup Iteration 3: 58987,052 us/op
# Warmup Iteration 4: 61368,128 us/op
# Warmup Iteration 5: 59257,690 us/op
Iteration 1: 60699,151 us/op
Iteration 2: 59754,186 us/op
Iteration 3: 60091,361 us/op
Iteration 4: 61224,621 us/op
Iteration 5: 58651,375 us/op
Iteration 6: 58365,153 us/op
Iteration 7: 58962,688 us/op
Iteration 8: 58993,352 us/op
Iteration 9: 58819,427 us/op
Iteration 10: 58550,841 us/op
# Run progress: 47,92% complete, ETA 00:09:35
# Fork: 3 of 3
# Warmup Iteration 1: 85371,543 us/op
# Warmup Iteration 2: 58821,258 us/op
# Warmup Iteration 3: 58546,736 us/op
# Warmup Iteration 4: 58518,930 us/op
# Warmup Iteration 5: 59124,297 us/op
Iteration 1: 58823,911 us/op
Iteration 2: 58633,122 us/op
Iteration 3: 58459,387 us/op
Iteration 4: 58571,716 us/op
Iteration 5: 58584,158 us/op
Iteration 6: 58584,505 us/op
Iteration 7: 58472,397 us/op
Iteration 8: 58647,381 us/op
Iteration 9: 64360,849 us/op
Iteration 10: 60359,720 us/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.ImmutableStringBenchmark.concatenationBenchmark":
59119,874 ±(99.9%) 841,652 us/op [Average]
(min, avg, max) = (58242,481, 59119,874, 64360,849), stdev = 1259,746
CI (99.9%): [58278,221, 59961,526] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 9.0.4, VM 9.0.4+11
# VM invoker: C:\Program Files\Java\jre-9.0.4\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughBuilderBenchmark
# Run progress: 50,00% complete, ETA 00:09:13
# Fork: 1 of 3
# Warmup Iteration 1: 262,703 ns/op
# Warmup Iteration 2: 213,253 ns/op
# Warmup Iteration 3: 214,540 ns/op
# Warmup Iteration 4: 211,447 ns/op
# Warmup Iteration 5: 211,299 ns/op
Iteration 1: 212,265 ns/op
Iteration 2: 210,657 ns/op
Iteration 3: 212,277 ns/op
Iteration 4: 219,824 ns/op
Iteration 5: 225,531 ns/op
Iteration 6: 206,097 ns/op
Iteration 7: 204,751 ns/op
Iteration 8: 211,672 ns/op
Iteration 9: 209,949 ns/op
Iteration 10: 208,630 ns/op
# Run progress: 52,08% complete, ETA 00:08:49
# Fork: 2 of 3
# Warmup Iteration 1: 263,284 ns/op
# Warmup Iteration 2: 200,613 ns/op
# Warmup Iteration 3: 194,637 ns/op
# Warmup Iteration 4: 195,592 ns/op
# Warmup Iteration 5: 198,620 ns/op
Iteration 1: 198,124 ns/op
Iteration 2: 199,164 ns/op
Iteration 3: 199,169 ns/op
Iteration 4: 208,831 ns/op
Iteration 5: 215,353 ns/op
Iteration 6: 205,850 ns/op
Iteration 7: 201,657 ns/op
Iteration 8: 212,089 ns/op
Iteration 9: 206,610 ns/op
Iteration 10: 201,656 ns/op
# Run progress: 54,17% complete, ETA 00:08:26
# Fork: 3 of 3
# Warmup Iteration 1: 261,702 ns/op
# Warmup Iteration 2: 197,009 ns/op
# Warmup Iteration 3: 202,197 ns/op
# Warmup Iteration 4: 203,103 ns/op
# Warmup Iteration 5: 210,418 ns/op
Iteration 1: 205,722 ns/op
Iteration 2: 204,451 ns/op
Iteration 3: 209,910 ns/op
Iteration 4: 203,296 ns/op
Iteration 5: 203,002 ns/op
Iteration 6: 207,542 ns/op
Iteration 7: 209,387 ns/op
Iteration 8: 202,788 ns/op
Iteration 9: 197,077 ns/op
Iteration 10: 201,708 ns/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughBuilderBenchmark":
207,168 ±(99.9%) 4,245 ns/op [Average]
(min, avg, max) = (197,077, 207,168, 225,531), stdev = 6,353
CI (99.9%): [202,923, 211,413] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 9.0.4, VM 9.0.4+11
# VM invoker: C:\Program Files\Java\jre-9.0.4\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughConcatenationBenchmark
# Run progress: 56,25% complete, ETA 00:08:03
# Fork: 1 of 3
# Warmup Iteration 1: 77,890 ns/op
# Warmup Iteration 2: 60,084 ns/op
# Warmup Iteration 3: 61,112 ns/op
# Warmup Iteration 4: 64,259 ns/op
# Warmup Iteration 5: 63,863 ns/op
Iteration 1: 58,276 ns/op
Iteration 2: 56,546 ns/op
Iteration 3: 56,680 ns/op
Iteration 4: 56,652 ns/op
Iteration 5: 57,838 ns/op
Iteration 6: 58,543 ns/op
Iteration 7: 56,616 ns/op
Iteration 8: 56,765 ns/op
Iteration 9: 56,704 ns/op
Iteration 10: 56,496 ns/op
# Run progress: 58,33% complete, ETA 00:07:40
# Fork: 2 of 3
# Warmup Iteration 1: 79,029 ns/op
# Warmup Iteration 2: 60,338 ns/op
# Warmup Iteration 3: 56,450 ns/op
# Warmup Iteration 4: 56,621 ns/op
# Warmup Iteration 5: 56,712 ns/op
Iteration 1: 56,811 ns/op
Iteration 2: 56,772 ns/op
Iteration 3: 58,599 ns/op
Iteration 4: 58,018 ns/op
Iteration 5: 57,401 ns/op
Iteration 6: 57,331 ns/op
Iteration 7: 56,742 ns/op
Iteration 8: 56,869 ns/op
Iteration 9: 56,881 ns/op
Iteration 10: 56,639 ns/op
# Run progress: 60,42% complete, ETA 00:07:17
# Fork: 3 of 3
# Warmup Iteration 1: 71,819 ns/op
# Warmup Iteration 2: 53,982 ns/op
# Warmup Iteration 3: 53,217 ns/op
# Warmup Iteration 4: 53,991 ns/op
# Warmup Iteration 5: 53,129 ns/op
Iteration 1: 53,270 ns/op
Iteration 2: 53,306 ns/op
Iteration 3: 54,263 ns/op
Iteration 4: 53,325 ns/op
Iteration 5: 54,777 ns/op
Iteration 6: 53,585 ns/op
Iteration 7: 56,112 ns/op
Iteration 8: 55,468 ns/op
Iteration 9: 53,991 ns/op
Iteration 10: 55,320 ns/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughConcatenationBenchmark":
56,220 ±(99.9%) 1,051 ns/op [Average]
(min, avg, max) = (53,270, 56,220, 58,599), stdev = 1,573
CI (99.9%): [55,169, 57,271] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 9.0.4, VM 9.0.4+11
# VM invoker: C:\Program Files\Java\jre-9.0.4\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughMessageFormatBuilder
# Run progress: 62,50% complete, ETA 00:06:54
# Fork: 1 of 3
# Warmup Iteration 1: 938,402 ns/op
# Warmup Iteration 2: 777,569 ns/op
# Warmup Iteration 3: 675,804 ns/op
# Warmup Iteration 4: 578,318 ns/op
# Warmup Iteration 5: 617,798 ns/op
Iteration 1: 595,885 ns/op
Iteration 2: 582,897 ns/op
Iteration 3: 581,880 ns/op
Iteration 4: 583,899 ns/op
Iteration 5: 587,891 ns/op
Iteration 6: 582,556 ns/op
Iteration 7: 573,807 ns/op
Iteration 8: 580,034 ns/op
Iteration 9: 580,055 ns/op
Iteration 10: 600,465 ns/op
# Run progress: 64,58% complete, ETA 00:06:31
# Fork: 2 of 3
# Warmup Iteration 1: 917,728 ns/op
# Warmup Iteration 2: 778,207 ns/op
# Warmup Iteration 3: 701,344 ns/op
# Warmup Iteration 4: 614,129 ns/op
# Warmup Iteration 5: 657,221 ns/op
Iteration 1: 607,015 ns/op
Iteration 2: 612,909 ns/op
Iteration 3: 583,067 ns/op
Iteration 4: 578,083 ns/op
Iteration 5: 581,597 ns/op
Iteration 6: 584,794 ns/op
Iteration 7: 579,920 ns/op
Iteration 8: 582,049 ns/op
Iteration 9: 580,960 ns/op
Iteration 10: 577,774 ns/op
# Run progress: 66,67% complete, ETA 00:06:08
# Fork: 3 of 3
# Warmup Iteration 1: 976,629 ns/op
# Warmup Iteration 2: 793,514 ns/op
# Warmup Iteration 3: 684,222 ns/op
# Warmup Iteration 4: 614,079 ns/op
# Warmup Iteration 5: 585,099 ns/op
Iteration 1: 699,791 ns/op
Iteration 2: 666,016 ns/op
Iteration 3: 619,701 ns/op
Iteration 4: 579,987 ns/op
Iteration 5: 576,779 ns/op
Iteration 6: 638,863 ns/op
Iteration 7: 607,345 ns/op
Iteration 8: 582,039 ns/op
Iteration 9: 579,164 ns/op
Iteration 10: 581,331 ns/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughMessageFormatBuilder":
594,952 ±(99.9%) 19,025 ns/op [Average]
(min, avg, max) = (573,807, 594,952, 699,791), stdev = 28,475
CI (99.9%): [575,927, 613,977] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 9.0.4, VM 9.0.4+11
# VM invoker: C:\Program Files\Java\jre-9.0.4\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughPatternBenchmark
# Run progress: 68,75% complete, ETA 00:05:45
# Fork: 1 of 3
# Warmup Iteration 1: 2299,834 ns/op
# Warmup Iteration 2: 1192,569 ns/op
# Warmup Iteration 3: 1119,558 ns/op
# Warmup Iteration 4: 1117,464 ns/op
# Warmup Iteration 5: 1113,444 ns/op
Iteration 1: 1114,229 ns/op
Iteration 2: 1113,023 ns/op
Iteration 3: 1112,185 ns/op
Iteration 4: 1108,222 ns/op
Iteration 5: 1108,988 ns/op
Iteration 6: 1108,674 ns/op
Iteration 7: 1109,976 ns/op
Iteration 8: 1109,831 ns/op
Iteration 9: 1109,610 ns/op
Iteration 10: 1107,814 ns/op
# Run progress: 70,83% complete, ETA 00:05:22
# Fork: 2 of 3
# Warmup Iteration 1: 2304,824 ns/op
# Warmup Iteration 2: 1199,471 ns/op
# Warmup Iteration 3: 1132,885 ns/op
# Warmup Iteration 4: 1129,351 ns/op
# Warmup Iteration 5: 1127,920 ns/op
Iteration 1: 1125,261 ns/op
Iteration 2: 1127,166 ns/op
Iteration 3: 1141,141 ns/op
Iteration 4: 1124,300 ns/op
Iteration 5: 1125,081 ns/op
Iteration 6: 1126,538 ns/op
Iteration 7: 1125,685 ns/op
Iteration 8: 1130,100 ns/op
Iteration 9: 1176,107 ns/op
Iteration 10: 1154,583 ns/op
# Run progress: 72,92% complete, ETA 00:04:59
# Fork: 3 of 3
# Warmup Iteration 1: 2358,123 ns/op
# Warmup Iteration 2: 1352,622 ns/op
# Warmup Iteration 3: 1156,702 ns/op
# Warmup Iteration 4: 1149,448 ns/op
# Warmup Iteration 5: 1149,654 ns/op
Iteration 1: 1147,214 ns/op
Iteration 2: 1180,265 ns/op
Iteration 3: 1181,957 ns/op
Iteration 4: 1155,407 ns/op
Iteration 5: 1140,645 ns/op
Iteration 6: 1133,507 ns/op
Iteration 7: 1139,044 ns/op
Iteration 8: 1139,680 ns/op
Iteration 9: 1137,071 ns/op
Iteration 10: 1137,626 ns/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughPatternBenchmark":
1131,698 ±(99.9%) 14,363 ns/op [Average]
(min, avg, max) = (1107,814, 1131,698, 1181,957), stdev = 21,499
CI (99.9%): [1117,334, 1146,061] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 9.0.4, VM 9.0.4+11
# VM invoker: C:\Program Files\Java\jre-9.0.4\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.OrdinalStringFormatBenchmark.formatThroughBuilderBenchmark
# Run progress: 75,00% complete, ETA 00:04:36
# Fork: 1 of 3
# Warmup Iteration 1: 60,124 ns/op
# Warmup Iteration 2: 53,887 ns/op
# Warmup Iteration 3: 50,428 ns/op
# Warmup Iteration 4: 53,202 ns/op
# Warmup Iteration 5: 51,629 ns/op
Iteration 1: 54,842 ns/op
Iteration 2: 59,136 ns/op
Iteration 3: 52,904 ns/op
Iteration 4: 53,913 ns/op
Iteration 5: 52,834 ns/op
Iteration 6: 54,876 ns/op
Iteration 7: 52,038 ns/op
Iteration 8: 51,615 ns/op
Iteration 9: 53,753 ns/op
Iteration 10: 55,080 ns/op
# Run progress: 77,08% complete, ETA 00:04:12
# Fork: 2 of 3
# Warmup Iteration 1: 69,893 ns/op
# Warmup Iteration 2: 70,767 ns/op
# Warmup Iteration 3: 54,095 ns/op
# Warmup Iteration 4: 52,366 ns/op
# Warmup Iteration 5: 51,154 ns/op
Iteration 1: 53,590 ns/op
Iteration 2: 59,785 ns/op
Iteration 3: 54,607 ns/op
Iteration 4: 53,504 ns/op
Iteration 5: 53,435 ns/op
Iteration 6: 53,093 ns/op
Iteration 7: 55,045 ns/op
Iteration 8: 56,632 ns/op
Iteration 9: 53,294 ns/op
Iteration 10: 53,475 ns/op
# Run progress: 79,17% complete, ETA 00:03:49
# Fork: 3 of 3
# Warmup Iteration 1: 67,840 ns/op
# Warmup Iteration 2: 60,608 ns/op
# Warmup Iteration 3: 55,115 ns/op
# Warmup Iteration 4: 51,854 ns/op
# Warmup Iteration 5: 51,892 ns/op
Iteration 1: 50,344 ns/op
Iteration 2: 52,877 ns/op
Iteration 3: 49,468 ns/op
Iteration 4: 49,513 ns/op
Iteration 5: 49,646 ns/op
Iteration 6: 49,113 ns/op
Iteration 7: 50,870 ns/op
Iteration 8: 51,113 ns/op
Iteration 9: 52,482 ns/op
Iteration 10: 53,757 ns/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.OrdinalStringFormatBenchmark.formatThroughBuilderBenchmark":
53,221 ±(99.9%) 1,691 ns/op [Average]
(min, avg, max) = (49,113, 53,221, 59,785), stdev = 2,531
CI (99.9%): [51,530, 54,912] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 9.0.4, VM 9.0.4+11
# VM invoker: C:\Program Files\Java\jre-9.0.4\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.OrdinalStringFormatBenchmark.formatThroughConcatenationBenchmark
# Run progress: 81,25% complete, ETA 00:03:26
# Fork: 1 of 3
# Warmup Iteration 1: 83,417 ns/op
# Warmup Iteration 2: 68,292 ns/op
# Warmup Iteration 3: 67,835 ns/op
# Warmup Iteration 4: 68,365 ns/op
# Warmup Iteration 5: 67,227 ns/op
Iteration 1: 70,120 ns/op
Iteration 2: 76,220 ns/op
Iteration 3: 69,923 ns/op
Iteration 4: 70,066 ns/op
Iteration 5: 70,546 ns/op
Iteration 6: 73,056 ns/op
Iteration 7: 74,891 ns/op
Iteration 8: 71,014 ns/op
Iteration 9: 71,251 ns/op
Iteration 10: 68,057 ns/op
# Run progress: 83,33% complete, ETA 00:03:03
# Fork: 2 of 3
# Warmup Iteration 1: 86,203 ns/op
# Warmup Iteration 2: 70,289 ns/op
# Warmup Iteration 3: 68,240 ns/op
# Warmup Iteration 4: 66,329 ns/op
# Warmup Iteration 5: 68,189 ns/op
Iteration 1: 70,755 ns/op
Iteration 2: 70,378 ns/op
Iteration 3: 66,964 ns/op
Iteration 4: 68,902 ns/op
Iteration 5: 66,020 ns/op
Iteration 6: 68,630 ns/op
Iteration 7: 67,040 ns/op
Iteration 8: 68,076 ns/op
Iteration 9: 66,649 ns/op
Iteration 10: 67,851 ns/op
# Run progress: 85,42% complete, ETA 00:02:41
# Fork: 3 of 3
# Warmup Iteration 1: 80,438 ns/op
# Warmup Iteration 2: 66,941 ns/op
# Warmup Iteration 3: 66,932 ns/op
# Warmup Iteration 4: 66,243 ns/op
# Warmup Iteration 5: 65,965 ns/op
Iteration 1: 66,020 ns/op
Iteration 2: 65,198 ns/op
Iteration 3: 66,240 ns/op
Iteration 4: 65,758 ns/op
Iteration 5: 65,622 ns/op
Iteration 6: 65,821 ns/op
Iteration 7: 65,357 ns/op
Iteration 8: 66,522 ns/op
Iteration 9: 65,876 ns/op
Iteration 10: 65,746 ns/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.OrdinalStringFormatBenchmark.formatThroughConcatenationBenchmark":
68,486 ±(99.9%) 1,936 ns/op [Average]
(min, avg, max) = (65,198, 68,486, 76,220), stdev = 2,897
CI (99.9%): [66,550, 70,421] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 9.0.4, VM 9.0.4+11
# VM invoker: C:\Program Files\Java\jre-9.0.4\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.OrdinalStringFormatBenchmark.formatThroughMessageFormatBenchmark
# Run progress: 87,50% complete, ETA 00:02:18
# Fork: 1 of 3
# Warmup Iteration 1: 1721,971 ns/op
# Warmup Iteration 2: 1404,417 ns/op
# Warmup Iteration 3: 1288,016 ns/op
# Warmup Iteration 4: 1221,914 ns/op
# Warmup Iteration 5: 1148,926 ns/op
Iteration 1: 1167,718 ns/op
Iteration 2: 1200,962 ns/op
Iteration 3: 1279,375 ns/op
Iteration 4: 1189,680 ns/op
Iteration 5: 1194,886 ns/op
Iteration 6: 1155,321 ns/op
Iteration 7: 1263,725 ns/op
Iteration 8: 1216,670 ns/op
Iteration 9: 1214,617 ns/op
Iteration 10: 1183,180 ns/op
# Run progress: 89,58% complete, ETA 00:01:55
# Fork: 2 of 3
# Warmup Iteration 1: 1687,903 ns/op
# Warmup Iteration 2: 1448,192 ns/op
# Warmup Iteration 3: 1379,461 ns/op
# Warmup Iteration 4: 1276,630 ns/op
# Warmup Iteration 5: 1295,725 ns/op
Iteration 1: 1211,845 ns/op
Iteration 2: 1198,077 ns/op
Iteration 3: 1212,626 ns/op
Iteration 4: 1186,964 ns/op
Iteration 5: 1239,643 ns/op
Iteration 6: 1222,036 ns/op
Iteration 7: 1275,295 ns/op
Iteration 8: 1213,864 ns/op
Iteration 9: 1212,271 ns/op
Iteration 10: 1242,831 ns/op
# Run progress: 91,67% complete, ETA 00:01:31
# Fork: 3 of 3
# Warmup Iteration 1: 1765,377 ns/op
# Warmup Iteration 2: 1601,591 ns/op
# Warmup Iteration 3: 1314,168 ns/op
# Warmup Iteration 4: 1185,941 ns/op
# Warmup Iteration 5: 1187,965 ns/op
Iteration 1: 1188,869 ns/op
Iteration 2: 1187,571 ns/op
Iteration 3: 1189,977 ns/op
Iteration 4: 1186,874 ns/op
Iteration 5: 1188,421 ns/op
Iteration 6: 1195,331 ns/op
Iteration 7: 1190,250 ns/op
Iteration 8: 1216,980 ns/op
Iteration 9: 1189,504 ns/op
Iteration 10: 1221,858 ns/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.OrdinalStringFormatBenchmark.formatThroughMessageFormatBenchmark":
1207,907 ±(99.9%) 19,414 ns/op [Average]
(min, avg, max) = (1155,321, 1207,907, 1279,375), stdev = 29,058
CI (99.9%): [1188,493, 1227,322] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 9.0.4, VM 9.0.4+11
# VM invoker: C:\Program Files\Java\jre-9.0.4\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.OrdinalStringFormatBenchmark.formatThroughPatternBenchmark
# Run progress: 93,75% complete, ETA 00:01:08
# Fork: 1 of 3
# Warmup Iteration 1: 3552,804 ns/op
# Warmup Iteration 2: 2018,183 ns/op
# Warmup Iteration 3: 2019,489 ns/op
# Warmup Iteration 4: 1971,642 ns/op
# Warmup Iteration 5: 1958,374 ns/op
Iteration 1: 1951,968 ns/op
Iteration 2: 1950,212 ns/op
Iteration 3: 1953,115 ns/op
Iteration 4: 1961,593 ns/op
Iteration 5: 1958,681 ns/op
Iteration 6: 1958,468 ns/op
Iteration 7: 1951,402 ns/op
Iteration 8: 1953,397 ns/op
Iteration 9: 1952,821 ns/op
Iteration 10: 2014,765 ns/op
# Run progress: 95,83% complete, ETA 00:00:45
# Fork: 2 of 3
# Warmup Iteration 1: 3928,522 ns/op
# Warmup Iteration 2: 2167,959 ns/op
# Warmup Iteration 3: 2066,428 ns/op
# Warmup Iteration 4: 1972,538 ns/op
# Warmup Iteration 5: 1948,498 ns/op
Iteration 1: 1948,707 ns/op
Iteration 2: 2003,769 ns/op
Iteration 3: 1974,530 ns/op
Iteration 4: 1944,253 ns/op
Iteration 5: 1973,301 ns/op
Iteration 6: 2066,764 ns/op
Iteration 7: 2128,009 ns/op
Iteration 8: 2042,947 ns/op
Iteration 9: 2052,664 ns/op
Iteration 10: 2049,175 ns/op
# Run progress: 97,92% complete, ETA 00:00:22
# Fork: 3 of 3
# Warmup Iteration 1: 2954,069 ns/op
# Warmup Iteration 2: 2011,884 ns/op
# Warmup Iteration 3: 1934,112 ns/op
# Warmup Iteration 4: 1929,191 ns/op
# Warmup Iteration 5: 1924,142 ns/op
Iteration 1: 1966,331 ns/op
Iteration 2: 1972,040 ns/op
Iteration 3: 1935,918 ns/op
Iteration 4: 1917,124 ns/op
Iteration 5: 1931,921 ns/op
Iteration 6: 1915,141 ns/op
Iteration 7: 1963,801 ns/op
Iteration 8: 1934,464 ns/op
Iteration 9: 1931,712 ns/op
Iteration 10: 1921,676 ns/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.OrdinalStringFormatBenchmark.formatThroughPatternBenchmark":
1972,689 ±(99.9%) 33,432 ns/op [Average]
(min, avg, max) = (1915,141, 1972,689, 2128,009), stdev = 50,040
CI (99.9%): [1939,257, 2006,121] (assumes normal distribution)
# Run complete. Total time: 00:18:23
Benchmark (N) Mode Cnt Score Error Units
ImmutableStringBenchmark.builderBenchmark 10 avgt 30 0,160 ± 0,004 us/op
ImmutableStringBenchmark.builderBenchmark 100 avgt 30 1,438 ± 0,107 us/op
ImmutableStringBenchmark.builderBenchmark 1000 avgt 30 15,963 ± 0,493 us/op
ImmutableStringBenchmark.builderBenchmark 10000 avgt 30 175,407 ± 3,039 us/op
ImmutableStringBenchmark.concatenationBenchmark 10 avgt 30 0,283 ± 0,007 us/op
ImmutableStringBenchmark.concatenationBenchmark 100 avgt 30 7,532 ± 0,220 us/op
ImmutableStringBenchmark.concatenationBenchmark 1000 avgt 30 612,002 ± 9,759 us/op
ImmutableStringBenchmark.concatenationBenchmark 10000 avgt 30 59119,874 ± 841,652 us/op
MetricsFormatBenchmark.formatThroughBuilderBenchmark N/A avgt 30 207,168 ± 4,245 ns/op
MetricsFormatBenchmark.formatThroughConcatenationBenchmark N/A avgt 30 56,220 ± 1,051 ns/op
MetricsFormatBenchmark.formatThroughMessageFormatBuilder N/A avgt 30 594,952 ± 19,025 ns/op
MetricsFormatBenchmark.formatThroughPatternBenchmark N/A avgt 30 1131,698 ± 14,363 ns/op
OrdinalStringFormatBenchmark.formatThroughBuilderBenchmark N/A avgt 30 53,221 ± 1,691 ns/op
OrdinalStringFormatBenchmark.formatThroughConcatenationBenchmark N/A avgt 30 68,486 ± 1,936 ns/op
OrdinalStringFormatBenchmark.formatThroughMessageFormatBenchmark N/A avgt 30 1207,907 ± 19,414 ns/op
OrdinalStringFormatBenchmark.formatThroughPatternBenchmark N/A avgt 30 1972,689 ± 33,432 ns/op
Неожиданный результат! Возможно даже для тех, кто внимательно следил за изменениями в Java 9: JEP-280.
Смотрим в генерируемый байткод для MetricsFormat:
public static java.lang.String formatThroughConcatenation(java.lang.String, int, long);
Code:
0: aload_0
1: iload_1
2: lload_2
3: invokedynamic #7, 0 // InvokeDynamic #0:makeConcatWithConstants:(Ljava/lang/String;IJ)Ljava/lang/String;
8: areturn
и байткод для OrdinalStringFormat:
public static java.lang.String formatThroughConcatenation(java.lang.String, java.lang.String, java.lang.String, java.lang.String);
Code:
0: aload_0
1: aload_1
2: aload_2
3: aload_3
4: invokedynamic #5, 0 // InvokeDynamic #0:makeConcatWithConstants:(Ljava/lang/String;Ljava/lang/String;Ljava/lang/String;Ljava/lang/String;)Ljava/lang/String;
9: areturn
За генерацию специализированных методов
makeConcatWithConstants отвечает StringConcatFactory. Специализация заключается в том, что для каждого случая генерируется отдельный метод: для MetricsFormat создался makeConcatWithConstants-метод, принимающий String, int и long, а из тела MetricsFormat.formatThroughConcatenation() ушла загрузка строковых констант (опкод ldc).По умолчанию в
StringConcatFactory выполняется стратегия Strategy.MH_INLINE_SIZED_EXACT — генерация с использованием MethodHandle с предварительным вычислением размера буфера, равного размеру результирующей строки: /**
* <p><b>{@link Strategy#MH_INLINE_SIZED_EXACT}: "MethodHandles inline,
* sized exactly".</b>
*
* <p>This strategy replicates what StringBuilders are doing: it builds the
* byte[] array on its own and passes that byte[] array to String
* constructor. This strategy requires access to some private APIs in JDK,
* most notably, the read-only Integer/Long.stringSize methods that measure
* the character length of the integers, and the private String constructor
* that accepts byte[] arrays without copying. While this strategy assumes a
* particular implementation details for String, this opens the door for
* building a very optimal concatenation sequence. This is the only strategy
* that requires porting if there are private JDK changes occur.
*/
private static final class MethodHandleInlineCopyStrategy { }
Это позволило обойти проблемы при форматировании строки с метрикой, наблюдавшиеся в сгенерированном коде для Java 8. Но так может получаться не всегда, как в случае примера из нашей задачи — результат хуже примерно на четверть. Результат получился хуже как относительно
StringBuilder, так и по отношению к результату на Java 8.OptimizeStringConcat
Интересен и тот факт, что метод
MetricsFormat.formatThroughConcatenation() показал в 4 раза лучший результат по сравнению с MetricsFormat.formatThroughBuilder()!Дело в том, что это не
makeConcatWithConstants так быстр, как недостаточно хорошо оптимизирован метод с вызовом StringBuilder. Как верно заметил apangin ниже в комментариях: заменив тип timestamp с long на int можно обнаружить, что разница между двумя реализациями уже не будет такой существенной.Особенность этого примера заключается в том, что
-XX:+OptimizeStringConcat не работает для StringBuilder.append(long), а появившийся в Java 9 механизм Indify String Concatenation лишён этого недостатка.Заключение
За рамками обсуждения остались compile-time оптимизации конкатенаций, о которых можно почитать в разделе спецификации, на который уже ссылался ранее (15.18.1), что тоже довольно любопытно.
Выдержка из спецификации
Example 15.18.1-1. String Concatenation
The example expression:
«The square root of 2 is » + Math.sqrt(2)
produces the result:
«The square root of 2 is 1.4142135623730952»
The + operator is syntactically left-associative, no matter whether it is determined by type analysis to represent string concatenation or numeric addition. In some cases care is required to get the desired result. For example, the expression:
a + b + c
is always regarded as meaning:
(a + b) + c
Therefore the result of the expression:
1 + 2 + " fiddlers"
is:
«3 fiddlers»
but the result of:
«fiddlers » + 1 + 2
is:
«fiddlers 12»
И остались без внимания незачейненные вызовы
StringBuilder.append() и разбитые на несколько независимых действий конкатенации. Хотя…Вот для таких методов
public static String formatThroughConcatenation(String metrics, int value, long timestamp) {
String result = metrics + " ";
result += value + " ";
result += timestamp;
return result;
}
public static String formatThroughBuilder(String metrics, int value, long timestamp) {
StringBuilder sb = new StringBuilder(metrics);
sb.append(" ");
sb.append(value);
sb.append(" ");
sb.append(timestamp);
return sb.toString();
}
генерируется такой байткод:
Байткод
public static java.lang.String formatThroughConcatenation(java.lang.String, int, long);
Code:
0: new #7 // class java/lang/StringBuilder
3: dup
4: invokespecial #8 // Method java/lang/StringBuilder."<init>":()V
7: aload_0
8: invokevirtual #9 // Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder;
11: ldc #10 // String
13: invokevirtual #9 // Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder;
16: invokevirtual #11 // Method java/lang/StringBuilder.toString:()Ljava/lang/String;
19: ast ore 4
21: new #7 // class java/lang/StringBuilder
24: dup
25: invokespecial #8 // Method java/lang/StringBuilder."<init>":()V
28: aload 4
30: invokevirtual #9 // Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder;
33: iload_1
34: invokevirtual #12 // Method java/lang/StringBuilder.append:(I)Ljava/lang/StringBuilder;
37: ldc #10 // String
39: invokevirtual #9 // Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder;
42: invokevirtual #11 // Method java/lang/StringBuilder.toString:()Ljava/lang/String;
45: astore 4
47: new #7 // class java/lang/StringBuilder
50: dup
51: invokespecial #8 // Method java/lang/StringBuilder."<init>":()V
54: aload 4
56: invokevirtual #9 // Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder;
59: lload_2
60: invokevirtual #13 // Method java/lang/StringBuilder.append:(J)Ljava/lang/StringBuilder;
63: invokevirtual #11 // Method java/lang/StringBuilder.toString:()Ljava/lang/String;
66: astore 4
68: aload 4
70: areturn
public static java.lang.String formatThroughBuilder(java.lang.String, int, long);
Code:
0: new #7 // class java/lang/StringBuilder
3: dup
4: aload_0
5: invokespecial #14 // Method java/lang/StringBuilder."<init>":(Ljava/lang/String;)V
8: astore 4
10: aload 4
12: ldc #10 // String
14: invokevirtual #9 // Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder;
17: pop
18: aload 4
20: iload_1
21: invokevirtual #12 // Method java/lang/StringBuilder.append:(I)Ljava/lang/StringBuilder;
24: pop
25: aload 4
27: ldc #10 // String
29: invokevirtual #9 // Method java/lang/StringBuilder.append:(Ljava/lang/String;)Ljava/lang/StringBuilder;
32: pop
33: aload 4
35: lload_2
36: invokevirtual #13 // Method java/lang/StringBuilder.append:(J)Ljava/lang/StringBuilder;
39: pop
40: aload 4
42: invokevirtual #11 // Method java/lang/StringBuilder.toString:()Ljava/lang/String;
45: areturn
В обоих случаях видно, что javac не предпринял каких-либо попыток для оптимизации этого. При этом в случае конкатенации теперь создаётся аж 3 экземпляра StringBuilder, второй метод тоже потяжелел.
Как это отразилось на производительности?
Benchmark Mode Cnt Score Error Units
Metrics...BuilderBenchmark avgt 30 196,029 ± 4,408 ns/op
Metrics...ConcatenationBenchmark avgt 30 444,483 ± 15,958 ns/op
Metrics...MessageFormatBuilder avgt 30 742,672 ± 12,152 ns/op
Metrics...PatternBenchmark avgt 30 1460,832 ± 24,075 ns/op
Результаты бенчмарка целиком
# JMH version: 1.20
# VM version: JDK 1.8.0_161, VM 25.161-b12
# VM invoker: C:\Program Files\Java\jre1.8.0_161\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughBuilderBenchmark
# Run progress: 0,00% complete, ETA 00:04:30
# Fork: 1 of 3
# Warmup Iteration 1: 271,429 ns/op
# Warmup Iteration 2: 196,309 ns/op
# Warmup Iteration 3: 199,026 ns/op
# Warmup Iteration 4: 204,715 ns/op
# Warmup Iteration 5: 211,038 ns/op
Iteration 1: 203,765 ns/op
Iteration 2: 222,851 ns/op
Iteration 3: 206,074 ns/op
Iteration 4: 190,166 ns/op
Iteration 5: 194,417 ns/op
Iteration 6: 193,172 ns/op
Iteration 7: 198,825 ns/op
Iteration 8: 195,664 ns/op
Iteration 9: 199,013 ns/op
Iteration 10: 193,255 ns/op
# Run progress: 8,33% complete, ETA 00:04:12
# Fork: 2 of 3
# Warmup Iteration 1: 260,478 ns/op
# Warmup Iteration 2: 187,885 ns/op
# Warmup Iteration 3: 190,952 ns/op
# Warmup Iteration 4: 190,522 ns/op
# Warmup Iteration 5: 188,620 ns/op
Iteration 1: 189,690 ns/op
Iteration 2: 189,475 ns/op
Iteration 3: 190,417 ns/op
Iteration 4: 189,153 ns/op
Iteration 5: 188,654 ns/op
Iteration 6: 195,455 ns/op
Iteration 7: 196,520 ns/op
Iteration 8: 198,637 ns/op
Iteration 9: 197,228 ns/op
Iteration 10: 192,514 ns/op
# Run progress: 16,67% complete, ETA 00:03:49
# Fork: 3 of 3
# Warmup Iteration 1: 264,150 ns/op
# Warmup Iteration 2: 189,343 ns/op
# Warmup Iteration 3: 192,978 ns/op
# Warmup Iteration 4: 192,287 ns/op
# Warmup Iteration 5: 191,892 ns/op
Iteration 1: 196,412 ns/op
Iteration 2: 193,130 ns/op
Iteration 3: 193,759 ns/op
Iteration 4: 194,552 ns/op
Iteration 5: 194,657 ns/op
Iteration 6: 194,341 ns/op
Iteration 7: 196,031 ns/op
Iteration 8: 195,504 ns/op
Iteration 9: 203,200 ns/op
Iteration 10: 194,339 ns/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughBuilderBenchmark":
196,029 ±(99.9%) 4,408 ns/op [Average]
(min, avg, max) = (188,654, 196,029, 222,851), stdev = 6,598
CI (99.9%): [191,621, 200,437] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 1.8.0_161, VM 25.161-b12
# VM invoker: C:\Program Files\Java\jre1.8.0_161\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughConcatenationBenchmark
# Run progress: 25,00% complete, ETA 00:03:26
# Fork: 1 of 3
# Warmup Iteration 1: 631,123 ns/op
# Warmup Iteration 2: 422,155 ns/op
# Warmup Iteration 3: 426,209 ns/op
# Warmup Iteration 4: 448,415 ns/op
# Warmup Iteration 5: 446,539 ns/op
Iteration 1: 422,996 ns/op
Iteration 2: 475,941 ns/op
Iteration 3: 461,148 ns/op
Iteration 4: 431,991 ns/op
Iteration 5: 450,734 ns/op
Iteration 6: 516,239 ns/op
Iteration 7: 431,390 ns/op
Iteration 8: 432,352 ns/op
Iteration 9: 452,826 ns/op
Iteration 10: 425,379 ns/op
# Run progress: 33,33% complete, ETA 00:03:03
# Fork: 2 of 3
# Warmup Iteration 1: 693,705 ns/op
# Warmup Iteration 2: 463,112 ns/op
# Warmup Iteration 3: 445,281 ns/op
# Warmup Iteration 4: 457,800 ns/op
# Warmup Iteration 5: 453,018 ns/op
Iteration 1: 437,737 ns/op
Iteration 2: 427,742 ns/op
Iteration 3: 443,569 ns/op
Iteration 4: 501,467 ns/op
Iteration 5: 446,490 ns/op
Iteration 6: 426,738 ns/op
Iteration 7: 427,594 ns/op
Iteration 8: 461,360 ns/op
Iteration 9: 425,101 ns/op
Iteration 10: 452,461 ns/op
# Run progress: 41,67% complete, ETA 00:02:40
# Fork: 3 of 3
# Warmup Iteration 1: 635,491 ns/op
# Warmup Iteration 2: 443,077 ns/op
# Warmup Iteration 3: 442,987 ns/op
# Warmup Iteration 4: 431,363 ns/op
# Warmup Iteration 5: 426,921 ns/op
Iteration 1: 433,445 ns/op
Iteration 2: 429,941 ns/op
Iteration 3: 438,845 ns/op
Iteration 4: 427,774 ns/op
Iteration 5: 426,440 ns/op
Iteration 6: 424,521 ns/op
Iteration 7: 430,905 ns/op
Iteration 8: 490,199 ns/op
Iteration 9: 449,060 ns/op
Iteration 10: 432,094 ns/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughConcatenationBenchmark":
444,483 ±(99.9%) 15,958 ns/op [Average]
(min, avg, max) = (422,996, 444,483, 516,239), stdev = 23,886
CI (99.9%): [428,524, 460,441] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 1.8.0_161, VM 25.161-b12
# VM invoker: C:\Program Files\Java\jre1.8.0_161\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughMessageFormatBuilder
# Run progress: 50,00% complete, ETA 00:02:17
# Fork: 1 of 3
# Warmup Iteration 1: 1161,265 ns/op
# Warmup Iteration 2: 998,957 ns/op
# Warmup Iteration 3: 845,871 ns/op
# Warmup Iteration 4: 742,562 ns/op
# Warmup Iteration 5: 735,021 ns/op
Iteration 1: 734,366 ns/op
Iteration 2: 742,179 ns/op
Iteration 3: 723,182 ns/op
Iteration 4: 728,268 ns/op
Iteration 5: 738,145 ns/op
Iteration 6: 739,328 ns/op
Iteration 7: 732,186 ns/op
Iteration 8: 774,538 ns/op
Iteration 9: 815,751 ns/op
Iteration 10: 714,448 ns/op
# Run progress: 58,33% complete, ETA 00:01:54
# Fork: 2 of 3
# Warmup Iteration 1: 1174,440 ns/op
# Warmup Iteration 2: 994,761 ns/op
# Warmup Iteration 3: 836,255 ns/op
# Warmup Iteration 4: 740,181 ns/op
# Warmup Iteration 5: 732,687 ns/op
Iteration 1: 741,292 ns/op
Iteration 2: 742,536 ns/op
Iteration 3: 743,853 ns/op
Iteration 4: 724,039 ns/op
Iteration 5: 739,011 ns/op
Iteration 6: 743,141 ns/op
Iteration 7: 735,273 ns/op
Iteration 8: 746,909 ns/op
Iteration 9: 733,629 ns/op
Iteration 10: 765,130 ns/op
# Run progress: 66,67% complete, ETA 00:01:31
# Fork: 3 of 3
# Warmup Iteration 1: 1184,020 ns/op
# Warmup Iteration 2: 969,928 ns/op
# Warmup Iteration 3: 832,638 ns/op
# Warmup Iteration 4: 735,386 ns/op
# Warmup Iteration 5: 745,396 ns/op
Iteration 1: 756,195 ns/op
Iteration 2: 749,304 ns/op
Iteration 3: 739,421 ns/op
Iteration 4: 754,232 ns/op
Iteration 5: 734,976 ns/op
Iteration 6: 737,265 ns/op
Iteration 7: 740,118 ns/op
Iteration 8: 742,716 ns/op
Iteration 9: 731,562 ns/op
Iteration 10: 737,156 ns/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughMessageFormatBuilder":
742,672 ±(99.9%) 12,152 ns/op [Average]
(min, avg, max) = (714,448, 742,672, 815,751), stdev = 18,188
CI (99.9%): [730,520, 754,824] (assumes normal distribution)
# JMH version: 1.20
# VM version: JDK 1.8.0_161, VM 25.161-b12
# VM invoker: C:\Program Files\Java\jre1.8.0_161\bin\java.exe
# VM options: <none>
# Warmup: 5 iterations, 1500 ms each
# Measurement: 10 iterations, 1500 ms each
# Timeout: 10 min per iteration
# Threads: 1 thread, will synchronize iterations
# Benchmark mode: Average time, time/op
# Benchmark: ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughPatternBenchmark
# Run progress: 75,00% complete, ETA 00:01:08
# Fork: 1 of 3
# Warmup Iteration 1: 2230,607 ns/op
# Warmup Iteration 2: 1705,927 ns/op
# Warmup Iteration 3: 1527,384 ns/op
# Warmup Iteration 4: 1492,499 ns/op
# Warmup Iteration 5: 1437,785 ns/op
Iteration 1: 1458,388 ns/op
Iteration 2: 1477,134 ns/op
Iteration 3: 1456,519 ns/op
Iteration 4: 1465,800 ns/op
Iteration 5: 1488,031 ns/op
Iteration 6: 1459,507 ns/op
Iteration 7: 1480,816 ns/op
Iteration 8: 1462,555 ns/op
Iteration 9: 1461,078 ns/op
Iteration 10: 1494,234 ns/op
# Run progress: 83,33% complete, ETA 00:00:45
# Fork: 2 of 3
# Warmup Iteration 1: 2186,425 ns/op
# Warmup Iteration 2: 1640,445 ns/op
# Warmup Iteration 3: 1409,303 ns/op
# Warmup Iteration 4: 1402,054 ns/op
# Warmup Iteration 5: 1411,979 ns/op
Iteration 1: 1429,291 ns/op
Iteration 2: 1412,831 ns/op
Iteration 3: 1426,304 ns/op
Iteration 4: 1417,528 ns/op
Iteration 5: 1507,471 ns/op
Iteration 6: 1444,355 ns/op
Iteration 7: 1435,535 ns/op
Iteration 8: 1402,223 ns/op
Iteration 9: 1400,843 ns/op
Iteration 10: 1401,743 ns/op
# Run progress: 91,67% complete, ETA 00:00:22
# Fork: 3 of 3
# Warmup Iteration 1: 2223,753 ns/op
# Warmup Iteration 2: 1766,516 ns/op
# Warmup Iteration 3: 1452,903 ns/op
# Warmup Iteration 4: 1462,324 ns/op
# Warmup Iteration 5: 1485,965 ns/op
Iteration 1: 1533,760 ns/op
Iteration 2: 1551,043 ns/op
Iteration 3: 1468,389 ns/op
Iteration 4: 1463,317 ns/op
Iteration 5: 1466,646 ns/op
Iteration 6: 1487,802 ns/op
Iteration 7: 1467,299 ns/op
Iteration 8: 1460,768 ns/op
Iteration 9: 1488,246 ns/op
Iteration 10: 1455,518 ns/op
Result "ru.gnkoshelev.jbreak2018.perf_tests.strings.MetricsFormatBenchmark.formatThroughPatternBenchmark":
1460,832 ±(99.9%) 24,075 ns/op [Average]
(min, avg, max) = (1400,843, 1460,832, 1551,043), stdev = 36,034
CI (99.9%): [1436,758, 1484,907] (assumes normal distribution)
# Run complete. Total time: 00:04:35
Benchmark Mode Cnt Score Error Units
MetricsFormatBenchmark.formatThroughBuilderBenchmark avgt 30 196,029 ± 4,408 ns/op
MetricsFormatBenchmark.formatThroughConcatenationBenchmark avgt 30 444,483 ± 15,958 ns/op
MetricsFormatBenchmark.formatThroughMessageFormatBuilder avgt 30 742,672 ± 12,152 ns/op
MetricsFormatBenchmark.formatThroughPatternBenchmark avgt 30 1460,832 ± 24,075 ns/op
Ожидаемо поплохело варианту
MetricsFormat.formatThroughConcatenation().А вот с оптимизацией pop/aload в
MetricsFormat.formatThroughBuilder() JIT-компилятор справился отлично — полученный результат по производительности ничем не отличается от зачейненного варианта. Тем не менее, обе версии использования StringBuilder не являются эквивалентными, например, OptimizeStringConcat умеет распознавать только зачейненный вариант использования StringBuilder.P.S.
Код бенчмарков лежит на github: jbreak2018-strings-perf-tests.
Заключительные две части выйдут с меньшим лагом. Третья часть выйдет в середине недели.
Комментарии (10)
gnkoshelev Автор
18.03.2018 15:38Касательно корректности рассуждений о производительности с учётом огромного числа эвристик HotSpot'а: задача объяснить наблюдаемое поведение выглядит значительно привлекательнее задачи оценки или сравнения производительности алгоритмов.
Но выбор в пользу первого варианта объяснялся форматом проведения викторины на конференции, когда по ответам можно было быстро отсортировать решения и уже дальше смотреть пояснения к ответам. В следующий раз стоит выбрать детерминированный вариант задач.
lany
18.03.2018 18:52И вот тут-то JIT-компилятор может хорошо покуражиться
JIT-то тут при чём? Основную работу делает собственно фабрика, генерируя цепочку методхэндлов, которые сперва считают суммарную длину всех строк, затем выделяют один массив точно нужного размера и всовывают его в строку через небезопасный конструктор.
gnkoshelev Автор
18.03.2018 20:07Согласен, в этом месте влияние JIT не настолько существенное — выше Андрей apangin намекнул на различия в определении длины строки под long в StringBuilder и StringConcatFactory. apangin, я же правильно понял, что речь об этом?
apangin
19.03.2018 02:53Да, и ещё то, что с
intтипом будет уже не важно, создаётся лиStringBuilder()с размером по умолчанию илиStringBuilder(metrics)с заранее предопределённым размером. В обоих случаях паттернnew StringBuilder(*).append()...append().toString()скомпилируется как интринсик без вызова Java кода, и производительность Concatenation vs. StringBuilder будет одинаковая, несмотря на различия в байткоде.
Если же в цепочке попадётся
append(long), то оптимизация не отработает — ну, не реализовали почему-то в JDK 8), то есть, будет честный вызов Java кода.gnkoshelev Автор
19.03.2018 09:15Ага, я чуть позже про
OptimizeStringConcatдописал.
Если же в цепочке попадётся append(long), то оптимизация не отработает — ну, не реализовали почему-то в JDK 8), то есть, будет честный вызов Java кода.
Судя по изменениям в stringopts.cpp в JDK 10/JDK 9 относительно JDK 8, то в новых версиях это по-прежнему не оптимизируется.lany
19.03.2018 10:48Ну так потому что уже особо не надо: JEP-280 срабатывает в подавляющем большинстве случаев (кроме модуля java.base и вручную написанных StringBuilder'ов). По сути дела и существующую оптимизацию если удалить, сильно хуже не станет.
apangin
За задачи и разбор +1, но делать выводы о производительности по байткоду не совсем корректно, как я показывал в презентации. Замени, например, timestamp с long на int и сравни заново… Довод про конструктор StringBuilder развалился на глазах, правда? И выводы будут уже совсем другие.
В этой же презентации про конкатенацию, кстати, тоже есть. Нельзя бенчмаркать StringBuilder и не упомянуть фичу Хотспота под названием OptimizeStringConcat.
gnkoshelev Автор
Спасибо!
За исключением тех случаев, когда javac генерирует идентичный байткод. :) В остальном согласен, и чем дальше (тот же JEP-280), тем поведение JIT-компилятора становится менее предсказуемым.
О, точно, я уже под утро заканчивал статью и про
OptimizeStringConcatсовсем забыл, а это важная штука.