После 28.02.2020 мы обнаружили, что наши кластеры Elasticsearch, используемые для обработки журналов (с полями даты), не выполнялись.
Это 64-битный сервер HotSpot (TM), виртуальная машина 18.9 (сборка 11.0.3 + 12-LTS), которую мы использовали для запуска кластеров Elasticsearch.
Журнал деоптимизации jstack & JVM привел нас для деоптимизации (причина = unstable_if) проверки високосного года во время joda:
stacktrace
jstack показывает работоспособные [объемные] потоки эластичного поиска, но на самом деле они заблокированы (согласно gstack) из-за JVM деоптимизация в BasicGJChronology. java: 185 и BasicGJChronology. java: 187。 Обе две строки являются проверкой високосного года.
jstack:
"elasticsearch[xxx][bulk][T#19]" #312 daemon prio=5 os_prio=0 cpu=1972224606.34ms elapsed=12348671.96s tid=0x00007f90a0006800 nid=0xdd41 runnable [0x00007f8f170ee000]
java.lang.Thread.State: RUNNABLE
at org.joda.time.chrono.BasicGJChronology.setYear(BasicGJChronology.java:185)
at org.joda.time.chrono.BasicYearDateTimeField.setExtended(BasicYearDateTimeField.java:92)
at org.joda.time.format.DateTimeParserBucket$SavedField.set(DateTimeParserBucket.java:568)
at org.joda.time.format.DateTimeParserBucket.computeMillis(DateTimeParserBucket.java:451)
at org.joda.time.format.DateTimeParserBucket.doParseMillis(DateTimeParserBucket.java:182)
at org.joda.time.format.DateTimeFormatter.parseMillis(DateTimeFormatter.java:826)
at org.elasticsearch.index.mapper.DateFieldMapper$DateFieldType.parse(DateFieldMapper.java:248)
at org.elasticsearch.index.mapper.DateFieldMapper.parseCreateField(DateFieldMapper.java:456)
at org.elasticsearch.index.mapper.FieldMapper.parse(FieldMapper.java:297)
--
"elasticsearch[xxx][bulk][T#20]" #315 daemon prio=5 os_prio=0 cpu=1975796442.21ms elapsed=12348662.71s tid=0x00007f92f4048000 nid=0xdd83 runnable [0x00007f8f16cea000]
java.lang.Thread.State: RUNNABLE
at org.joda.time.chrono.BasicGJChronology.setYear(BasicGJChronology.java:187)
at org.joda.time.chrono.BasicYearDateTimeField.setExtended(BasicYearDateTimeField.java:92)
at org.joda.time.format.DateTimeParserBucket$SavedField.set(DateTimeParserBucket.java:568)
at org.joda.time.format.DateTimeParserBucket.computeMillis(DateTimeParserBucket.java:451)
at org.joda.time.format.DateTimeParserBucket.doParseMillis(DateTimeParserBucket.java:182)
at org.joda.time.format.DateTimeFormatter.parseMillis(DateTimeFormatter.java:826)
at org.elasticsearch.index.mapper.DateFieldMapper$DateFieldType.parse(DateFieldMapper.java:248)
at org.elasticsearch.index.mapper.DateFieldMapper.parseCreateField(DateFieldMapper.java:456)
at org.elasticsearch.index.mapper.FieldMapper.parse(FieldMapper.java:297)
gstack вышеуказанных объемных потоков :
#0 0x00007f3cf8f566d5 in pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0
#1 0x00007f3cf7ef8ef3 in os::PlatformEvent::park() () from /usr/java/jdk-11.0.3/lib/server/libjvm.so
#2 0x00007f3cf7e9feb8 in Monitor::lock_without_safepoint_check() () from /usr/java/jdk-11.0.3/lib/server/libjvm.so
#3 0x00007f3cf79977f3 in Events::log(Thread*, char const*, ...) () from /usr/java/jdk-11.0.3/lib/server/libjvm.so
#4 0x00007f3cf799411a in Deoptimization::uncommon_trap_inner(JavaThread*, int) () from /usr/java/jdk-11.0.3/lib/server/libjvm.so
#5 0x00007f3cf79973d2 in Deoptimization::uncommon_trap(JavaThread*, int, int) () from /usr/java/jdk-11.0.3/lib/server/libjvm.so
фрагменты кода от BasicGJChronology. java:
long setYear(long instant, int year) {
int thisYear = getYear(instant);
int dayOfYear = getDayOfYear(instant, thisYear);
int millisOfDay = getMillisOfDay(instant);
if (dayOfYear > (31 + 28)) { // after Feb 28
if (isLeapYear(thisYear)) { // LINE 185
// Current date is Feb 29 or later.
if (!isLeapYear(year)) { // LINE 187
// Moving to a non-leap year, Feb 29 does not exist.
dayOfYear--;
}
} else {
// Current date is Mar 01 or later.
if (isLeapYear(year)) {
// Moving to a leap year, account for Feb 29.
dayOfYear++;
}
}
}
...
График пламени
От левой вершины на графике вы можете найти деоптимизацию.
журнал деоптимизации в hs_err_pidxxx.log
Deoptimization events (10 events):
Event: 12413938.027 Thread 0x00007f6174013000 Uncommon trap: reason=unstable_if action=none pc=0x00007f65f543ff88 method=org.joda.time.chrono.BasicGJChronology.setYear(JI)J @ 36 c2
Event: 12413938.027 Thread 0x00007f6174013000 Uncommon trap: reason=unstable_if action=none pc=0x00007f65f543ff88 method=org.joda.time.chrono.BasicGJChronology.setYear(JI)J @ 36 c2
вопросы
Как мы можем смягчить влияние деоптимизации на производительность? Кажется, это больше всего влияет не на стоимость JIT-компиляции, а на pthread_cond_wait ведения журнала?
Кластеры работали более года. Будет ли повторный перезапуск решить unstable_if?
Почему это unstable_if? Извините, я ничего не знаю о тактике производительности HotSpot. Но мое внутреннее чувство заключается в том, что состояние должно быть очень стабильным после високосного дня (все еще нестабильным в 3/5/2020). 31.12.2020 меня тоже волнует, так как я понятия не имею о unstable_if.