высокая загрузка процессора на openjdk zgc

Question

Я пытаюсь использовать zgc в среде продукта, поэтому я обновил jdk с jdk8 до openjdk 15, tomcat 8 до tomcat 8.5 и параметры, связанные с gc, но использование процессора увеличивается до 1000+% через несколько часов после запуска jvm (нормальное использование процессора должно быть 100-300%). Иногда, когда процессор высок, в файле журнала есть много безопасных точек ICBufferFull:

[2020-11-12T19:00:43.669+0800] Safepoint "ICBufferFull", Time since last: 41374119 ns, Reaching safepoint: 2026134 ns, At safepoint: 85993 ns, Total: 2112127 ns
[2020-11-12T19:00:43.672+0800] Safepoint "ICBufferFull", Time since last: 2521598 ns, Reaching safepoint: 1109894 ns, At safepoint: 57235 ns, Total: 1167129 ns
[2020-11-12T19:00:43.676+0800] Safepoint "ICBufferFull", Time since last: 2892867 ns, Reaching safepoint: 1240834 ns, At safepoint: 59633 ns, Total: 1300467 ns
[2020-11-12T19:00:43.681+0800] Safepoint "ICBufferFull", Time since last: 2870110 ns, Reaching safepoint: 1425837 ns, At safepoint: 54052 ns, Total: 1479889 ns

Если перевести узел в автономный режим примерно на 30 секунд, процессор отключается, а затем переводится в режим онлайн, он будет нормально работать в течение нескольких часов, пока процессор снова не перейдет в высокий уровень. Я проверил исходный код, ICBufferFull означает "заполнение буферов встроенного кеша", но я не могу найти возможность увеличить его, может ли кто-нибудь помочь в этом? благодаря!

параметры gc:

export JAVA_OPTS='-Xms10g -Xmx10g -XX:+UseLargePages -XX:ZAllocationSpikeTolerance=5 -XX:ParallelGCThreads=8 -XX:ConcGCThreads=4 -Xss2m -XX:+UseZGC -Xlog:gc,gc+phases,safepoint:file=/logs/gc.log:t:filecount=10,filesize=10m -XX:+HeapDumpOnOutOfMemoryError'

edit1:

У меня есть еще один хост, который хорошо работает, все еще работает в jdk8 с cms в качестве ссылки, запросы к 2 хостам почти идентичны.

Профилировал с помощью async-profile, самый горячий метод - java/lang/ThreadLocal$ThreadLocalMap.getEntryAfterMiss, что произошло на 50+%, самый горячий нативный метод - ZMark::try_mark_object(ZMarkCache*, unsigned long, bool), что составило всего 0,41%. Я проверил локальный исходный код потока в jdk8 и openjdk15, похоже, не изменился.

edit2:

Я нашел аналогичную ошибку в JIRA, мое приложение тоже связано с lucene, и из журнала gc, когда количество слабых ссылок составляет 1 млн +, использование велико. так что вопрос будет в том, как более агрессивно собирать слабые ссылки в zgc?

edit3:

Из следующих журналов, в которых System.gc() вызывается каждые 3 секунды, кажется, что мое приложение создало слишком много слабых ссылок. но странно, что произведенный счет продолжает расти после запуска. запросы почти постоянно с 11:00-17:00. Обратите внимание, что cpu упал с 600% до 400% автоматически после GC(9821), поставлено в очередь ~250K. GC(10265) узел был отключен, поставлен в очередь ~770К. почему количество поставленных в очередь невелико в течение длительного времени, означает ли это, что объекты не возвращаются полностью?

[2020-11-19T11:00:00.245+0800] GC(992) Weak: 155658 encountered, 72334 discovered, 0 enqueued
[2020-11-19T12:00:00.397+0800] GC(2194) Weak: 220462 encountered, 122216 discovered, 1380 enqueued
[2020-11-19T12:00:03.411+0800] GC(2195) Weak: 220598 encountered, 107228 discovered, 677 enqueued
[2020-11-19T13:00:00.497+0800] GC(3395) Weak: 222536 encountered, 82199 discovered, 1713 enqueued
[2020-11-19T14:00:00.647+0800] GC(4613) Weak: 443946 encountered, 291651 discovered, 292 enqueued
[2020-11-19T15:00:01.173+0800] GC(5819) Weak: 338065 encountered, 124351 discovered, 815 enqueued
[2020-11-19T16:00:01.283+0800] GC(7022) Weak: 459070 encountered, 298932 discovered, 353 enqueued
[2020-11-19T17:00:01.426+0800] GC(8222) Weak: 688162 encountered, 519369 discovered, 4648 enqueued
[2020-11-19T16:00:01.283+0800] GC(7022) Weak: 459070 encountered, 298932 discovered, 353 enqueued
[2020-11-19T17:00:01.426+0800] GC(8222) Weak: 688162 encountered, 519369 discovered, 4648 enqueued
[2020-11-19T18:00:01.556+0800] GC(9430) Weak: 1078757 encountered, 928748 discovered, 1691 enqueued
[2020-11-19T18:18:43.595+0800] GC(9821) Weak: 1022080 encountered, 841168 discovered, 247352 enqueued
[2020-11-19T18:18:46.592+0800] GC(9822) Weak: 774253 encountered, 568564 discovered, 3938 enqueued
[2020-11-19T18:40:49.616+0800] GC(10265) Weak: 842081 encountered, 788825 discovered, 767288 enqueued
[2020-11-19T18:40:52.593+0800] GC(10266) Weak: 74876 encountered, 18186 discovered, 1 enqueued

Answer 1

Современные сборщики мусора задерживают сбор слабодоступных объектов.

Коллекции инициированы System.gc() всегда обрабатывают малодоступные объекты и по умолчанию являются параллельными, поэтому вы можете реализовать периодическую задачу, вызывающую метод.

Answer 2

Эта проблема, наконец, оказалась проблемой jdk, которая должна была быть решена в jdk16, и ее можно было обойти, создав пул потоков, который будет завершать старый поток и периодически генерировать новый поток. Я почему-то переместил свое приложение на причал, модифицированный пул потоков причала здесь. Теперь он отлично работает в течение нескольких дней, возьмите это, если кто-то столкнулся с той же проблемой.