Только поутихли страсти с первой части разбора, вышедшей на прошлой неделе, как публикую продолжение: сегодня речь пойдёт о второй задаче.
Код второй задачи:
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 FilesJavajre1.8.0_161binjava.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 FilesJavajre1.8.0_161binjava.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 FilesJavajre1.8.0_161binjava.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 FilesJavajre1.8.0_161binjava.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 FilesJavajre1.8.0_161binjava.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 FilesJavajre1.8.0_161binjava.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 FilesJavajre1.8.0_161binjava.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 FilesJavajre1.8.0_161binjava.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
— использованиеStringBuilder
formatThroughMessageFormat
— использование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 FilesJavajre1.8.0_161binjava.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 FilesJavajre1.8.0_161binjava.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 FilesJavajre1.8.0_161binjava.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 FilesJavajre1.8.0_161binjava.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 FilesJavajre1.8.0_161binjava.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 FilesJavajre1.8.0_161binjava.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 FilesJavajre1.8.0_161binjava.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 FilesJavajre1.8.0_161binjava.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 дают одинаковый результат.
Статистика
Эта задача была самой простой из предложенных — её правильно решили 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
.
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 FilesJavajre-9.0.4binjava.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 FilesJavajre-9.0.4binjava.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 FilesJavajre-9.0.4binjava.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 FilesJavajre-9.0.4binjava.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 FilesJavajre-9.0.4binjava.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 FilesJavajre-9.0.4binjava.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 FilesJavajre-9.0.4binjava.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 FilesJavajre-9.0.4binjava.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 FilesJavajre-9.0.4binjava.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 FilesJavajre-9.0.4binjava.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 FilesJavajre-9.0.4binjava.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 FilesJavajre-9.0.4binjava.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 FilesJavajre-9.0.4binjava.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 FilesJavajre-9.0.4binjava.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 FilesJavajre-9.0.4binjava.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 FilesJavajre-9.0.4binjava.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).
И вот тут-то JIT-компилятор может хорошо покуражиться, что оказалось весьма заметно для форматирования строки с метрикой — результат оказался лучше StringBuilder
в 4 раза!
Но так может получаться не всегда, как в случае примера из нашей задачи — результат хуже примерно на четверть. Результат получился хуже как относительно StringBuilder
, так и по отношению к результату на Java 8.
Заключение
За рамками обсуждения остались 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 FilesJavajre1.8.0_161binjava.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 FilesJavajre1.8.0_161binjava.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 FilesJavajre1.8.0_161binjava.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 FilesJavajre1.8.0_161binjava.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-компилятор справился отлично — полученный результат по производительности ничем не отличается от зачейненного варианта.
P.S.
Код бенчмарков лежит на github: jbreak2018-strings-perf-tests.
Заключительные две части выйдут с меньшим лагом. Третья часть выйдет в середине недели.
Автор: Григорий Кошелев