Медленное приложение, частые зависания JVM с однопроцессорными настройками и Java 12+ - PullRequest
24 голосов
/ 23 апреля 2020

У нас есть клиентское приложение (с 10+ лет разработки). Его JDK был недавно обновлен с OpenJDK 11 до OpenJDK 14. На однопроцессорных установках (гиперпоточность отключена) Windows 10 (и на машинах VirtualBox только с одним доступным ЦП) приложение запускается довольно медленно по сравнению с Java 11. Кроме того, большую часть времени оно использует 100% ЦП. Мы могли бы также воспроизвести проблему с установкой привязки процессора только к одному ЦП (c:\windows\system32\cmd.exe /C start /affinity 1 ...).

Некоторые измерения при запуске приложения и выполнении запроса с минимальным ручным взаимодействием на моей машине VirtualBox:

  • OpenJDK 11.0.2: 36 секунд
  • OpenJDK 13.0.2: ~ 1,5 минуты
  • OpenJDK 13.0.2 с -XX:-UseBiasedLocking: 46 секунд
  • OpenJDK 13.0.2 с -XX:-ThreadLocalHandshakes: 40 секунд
  • OpenJDK 14: 5-6 минут
  • OpenJDK 14 с -XX:-UseBiasedLocking: 3-3,5 минуты
  • OpenJDK 15 EA Build 20: ~ 4,5 минуты

Изменен только используемый JDK (и упомянутые опции). (-XX:-ThreadLocalHandshakes недоступно в Java 14.)

Мы попытались записать, что JDK 14 делает с -Xlog:all=debug:file=app.txt:uptime,tid,level,tags:filecount=50.

Подсчет строк журнала за каждую секунду кажется довольно плавным с OpenJDK 11.0.2:

$ cat jdk11-log/app* | grep "^\[" | cut -d. -f 1 | cut -d[ -f 2 | sort | uniq -c | sort -k 2 -n
  30710 0
  44012 1
  55461 2
  55974 3
  27182 4
  41292 5
  43796 6
  51889 7
  54170 8
  58850 9
  51422 10
  44378 11
  41405 12
  53589 13
  41696 14
  29526 15
   2350 16
  50228 17
  62623 18
  42684 19
  45045 20

С другой стороны, OpenJDK 14, кажется, имеет интересные периоды тишины:

$ cat jdk14-log/app* | grep "^\[" | cut -d. -f 1 | cut -d[ -f 2 | sort | uniq -c | sort -k 2 -n
   7726 0
   1715 5
  10744 6
   4341 11
  42792 12
  45979 13
  38783 14
  17253 21
  34747 22
   1025 28
   2079 33
   2398 39
   3016 44

Итак, что происходит между секундами 1-4, 7-10 и 14-20?

...
[0.350s][7248][debug][class,resolve        ] jdk.internal.ref.CleanerFactory$1 java.lang.Thread CleanerFactory.java:45
[0.350s][7248][debug][class,resolve        ] jdk.internal.ref.CleanerImpl java.lang.Thread CleanerImpl.java:117
[0.350s][7248][info ][biasedlocking        ] Aligned thread 0x000000001727e010 to 0x000000001727e800
[0.350s][7248][info ][os,thread            ] Thread started (tid: 2944, attributes: stacksize: default, flags: CREATE_SUSPENDED STACK_SIZE_PARAM_IS)
[0.350s][6884][info ][os,thread            ] Thread is alive (tid: 6884).
[0.350s][6884][debug][os,thread            ] Thread 6884 stack dimensions: 0x00000000175b0000-0x00000000176b0000 (1024k).
[0.350s][6884][debug][os,thread            ] Thread 6884 stack guard pages activated: 0x00000000175b0000-0x00000000175b4000.
[0.350s][7248][debug][thread,smr           ] tid=7248: Threads::add: new ThreadsList=0x0000000017254500
[0.350s][7248][debug][thread,smr           ] tid=7248: ThreadsSMRSupport::free_list: threads=0x0000000017253d50 is freed.
[0.350s][2944][info ][os,thread            ] Thread is alive (tid: 2944).
[0.350s][2944][debug][os,thread            ] Thread 2944 stack dimensions: 0x00000000177b0000-0x00000000178b0000 (1024k).
[0.350s][2944][debug][os,thread            ] Thread 2944 stack guard pages activated: 0x00000000177b0000-0x00000000177b4000.
[0.351s][2944][debug][class,resolve        ] java.lang.Thread java.lang.Runnable Thread.java:832
[0.351s][2944][debug][class,resolve        ] jdk.internal.ref.CleanerImpl jdk.internal.misc.InnocuousThread CleanerImpl.java:135
[0.351s][2944][debug][class,resolve        ] jdk.internal.ref.CleanerImpl jdk.internal.ref.PhantomCleanable CleanerImpl.java:138
[0.351s][2944][info ][biasedlocking,handshake] JavaThread 0x000000001727e800 handshaking JavaThread 0x000000000286d800 to revoke object 0x00000000c0087f78
[0.351s][2944][debug][vmthread               ] Adding VM operation: HandshakeOneThread
[0.351s][6708][debug][vmthread               ] Evaluating non-safepoint VM operation: HandshakeOneThread
[0.351s][6708][debug][vmoperation            ] begin VM_Operation (0x00000000178af250): HandshakeOneThread, mode: no safepoint, requested by thread 0x000000001727e800

# no log until 5.723s

[5.723s][7248][info ][biasedlocking          ]   Revoked bias of currently-unlocked object
[5.723s][7248][debug][handshake,task         ] Operation: RevokeOneBias for thread 0x000000000286d800, is_vm_thread: false, completed in 94800 ns
[5.723s][7248][debug][class,resolve          ] java.util.zip.ZipFile$CleanableResource java.lang.ref.Cleaner ZipFile.java:715
[5.723s][7248][debug][class,resolve          ] java.lang.ref.Cleaner jdk.internal.ref.CleanerImpl$PhantomCleanableRef Cleaner.java:220
[5.723s][7248][debug][class,resolve          ] java.util.zip.ZipFile$CleanableResource java.util.WeakHashMap ZipFile.java:716
...

Вторая пауза чуть позже:

...
[6.246s][7248][info ][class,load              ] java.awt.Graphics source: jrt:/java.desktop
[6.246s][7248][debug][class,load              ]  klass: 0x0000000100081a00 super: 0x0000000100001080 loader: [loader data: 0x0000000002882bd0 of 'bootstrap'] bytes: 5625 checksum: 0025818f
[6.246s][7248][debug][class,resolve           ] java.awt.Graphics java.lang.Object (super)
[6.246s][7248][info ][class,loader,constraints] updating constraint for name java/awt/Graphics, loader 'bootstrap', by setting class object
[6.246s][7248][debug][jit,compilation         ]   19       4       java.lang.Object::<init> (1 bytes)   made not entrant
[6.246s][7248][debug][vmthread                ] Adding VM operation: HandshakeAllThreads
[6.246s][6708][debug][vmthread                ] Evaluating non-safepoint VM operation: HandshakeAllThreads
[6.246s][6708][debug][vmoperation             ] begin VM_Operation (0x000000000203ddf8): HandshakeAllThreads, mode: no safepoint, requested by thread 0x000000000286d800
[6.246s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x00000000026b0800, is_vm_thread: true, completed in 1400 ns
[6.246s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x00000000026bb800, is_vm_thread: true, completed in 700 ns
[6.246s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x00000000026ef800, is_vm_thread: true, completed in 100 ns
[6.246s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x00000000026f0800, is_vm_thread: true, completed in 100 ns
[6.246s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x00000000026f1800, is_vm_thread: true, completed in 100 ns
[6.246s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x00000000026f4800, is_vm_thread: true, completed in 100 ns
[6.247s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x0000000002768800, is_vm_thread: true, completed in 100 ns
[6.247s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x000000000276e000, is_vm_thread: true, completed in 100 ns
[6.247s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x0000000017268800, is_vm_thread: true, completed in 100 ns
[6.247s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x000000001727e800, is_vm_thread: true, completed in 800 ns

# no log until 11.783s

[11.783s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x000000000286d800, is_vm_thread: true, completed in 6300 ns
[11.783s][6708][info ][handshake               ] Handshake "Deoptimize", Targeted threads: 11, Executed by targeted threads: 0, Total completion time: 5536442500 ns
[11.783s][6708][debug][vmoperation             ] end VM_Operation (0x000000000203ddf8): HandshakeAllThreads, mode: no safepoint, requested by thread 0x000000000286d800
[11.783s][7248][debug][protectiondomain        ] Checking package access
[11.783s][7248][debug][protectiondomain        ] class loader: a 'jdk/internal/loader/ClassLoaders$AppClassLoader'{0x00000000c0058628} protection domain: a 'java/security/ProtectionDomain'{0x00000000c058b948} loading: 'java/awt/Graphics'
[11.783s][7248][debug][protectiondomain        ] granted
[11.783s][7248][debug][class,resolve           ] sun.launcher.LauncherHelper java.awt.Graphics LauncherHelper.java:816 (reflection)
[11.783s][7248][debug][class,resolve           ] jdk.internal.reflect.Reflection [Ljava.lang.reflect.Method; Reflection.java:300
[11.783s][7248][debug][class,preorder          ] java.lang.PublicMethods$MethodList source: C:\Users\example\AppData\Local\example\stable\jdk\lib\modules
...

Затем третья:

...
[14.578s][7248][debug][class,preorder          ] java.lang.InheritableThreadLocal source: C:\Users\example\AppData\Local\example\stable\jdk\lib\modules
[14.578s][7248][info ][class,load              ] java.lang.InheritableThreadLocal source: jrt:/java.base
[14.578s][7248][debug][class,load              ]  klass: 0x0000000100124740 super: 0x0000000100021a18 loader: [loader data: 0x0000000002882bd0 of 'bootstrap'] bytes: 1338 checksum: 8013ed55
[14.578s][7248][debug][class,resolve           ] java.lang.InheritableThreadLocal java.lang.ThreadLocal (super)
[14.578s][7248][debug][jit,compilation         ]  699       3       java.lang.ThreadLocal::get (38 bytes)   made not entrant
[14.578s][7248][debug][vmthread                ] Adding VM operation: HandshakeAllThreads
[14.578s][6708][debug][vmthread                ] Evaluating non-safepoint VM operation: HandshakeAllThreads
[14.578s][6708][debug][vmoperation             ] begin VM_Operation (0x000000000203d228): HandshakeAllThreads, mode: no safepoint, requested by thread 0x000000000286d800
[14.578s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x00000000026b0800, is_vm_thread: true, completed in 1600 ns
[14.578s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x00000000026bb800, is_vm_thread: true, completed in 900 ns
[14.578s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x00000000026ef800, is_vm_thread: true, completed in 100 ns
[14.578s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x00000000026f0800, is_vm_thread: true, completed in 100 ns
[14.578s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x00000000026f1800, is_vm_thread: true, completed in 100 ns
[14.578s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x00000000026f4800, is_vm_thread: true, completed in 0 ns
[14.578s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x0000000002768800, is_vm_thread: true, completed in 0 ns
[14.578s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x000000000276e000, is_vm_thread: true, completed in 0 ns
[14.578s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x0000000017268800, is_vm_thread: true, completed in 0 ns
[14.579s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x000000001727e800, is_vm_thread: true, completed in 900 ns

# no log until 21.455s

[21.455s][6708][debug][handshake,task          ] Operation: Deoptimize for thread 0x000000000286d800, is_vm_thread: true, completed in 12100 ns
[21.455s][6708][info ][handshake               ] Handshake "Deoptimize", Targeted threads: 11, Executed by targeted threads: 0, Total completion time: 6876829000 ns
[21.455s][6708][debug][vmoperation             ] end VM_Operation (0x000000000203d228): HandshakeAllThreads, mode: no safepoint, requested by thread 0x000000000286d800
[21.455s][7248][debug][class,resolve           ] sun.security.jca.Providers java.lang.InheritableThreadLocal Providers.java:39
[21.455s][7248][info ][class,init              ] 1251 Initializing 'java/lang/InheritableThreadLocal'(no method) (0x0000000100124740)
[21.455s][7248][debug][class,resolve           ] java.lang.InheritableThreadLocal java.lang.ThreadLocal InheritableThreadLocal.java:57
[21.456s][7248][debug][class,preorder          ] sun.security.jca.ProviderList source: C:\Users\example\AppData\Local\example\stable\jdk\lib\modules
[21.456s][7248][info ][class,load              ] sun.security.jca.ProviderList source: jrt:/java.base
[21.456s][7248][debug][class,load              ]  klass: 0x00000001001249a8 super: 0x0000000100001080 loader: [loader data: 0x0000000002882bd0 of 'bootstrap'] bytes: 11522 checksum: bdc239d2
[21.456s][7248][debug][class,resolve           ] sun.security.jca.ProviderList java.lang.Object (super)
...

Следующие две строки кажутся интересно:

[11.783s][6708][info ][handshake               ] Handshake "Deoptimize", Targeted threads: 11, Executed by targeted threads: 0, Total completion time: 5536442500 ns
[21.455s][6708][info ][handshake               ] Handshake "Deoptimize", Targeted threads: 11, Executed by targeted threads: 0, Total completion time: 6876829000 ns

Это нормально, что эти рукопожатия заняли 5,5 и 6,8 секунды?

Я испытал такое же замедление (и похожие журналы) с демонстрационным приложением update4j (который совершенно не связан с нашим приложением), работающий с этой командой:

Z:\swing>\jdk-14\bin\java -Xlog:all=debug:file=app.txt:uptime,tid,level,tags:filecount=50 \
    -jar update4j-1.4.5.jar --remote http://docs.update4j.org/demo/setup.xml

Что мне нужно искать, чтобы снова ускорить работу нашего приложения на однопроцессорных Windows 10 установках? Можно ли это исправить, изменив что-то в нашем приложении или добавив аргументы JVM?

Это ошибка JDK, я должен сообщить об этом?

update 2020-04-25:

Насколько я вижу, файлы журналов также содержат журналы G C. Это первые журналы G C:

$ cat app.txt.00 | grep "\[gc"
[0.016s][7248][debug][gc,heap          ] Minimum heap 8388608  Initial heap 60817408  Maximum heap 1073741824
[0.017s][7248][info ][gc,heap,coops    ] Heap address: 0x00000000c0000000, size: 1024 MB, Compressed Oops mode: 32-bit
[0.018s][7248][info ][gc               ] Using Serial
[22.863s][6708][info ][gc,start                ] GC(0) Pause Young (Allocation Failure)
[22.863s][6708][debug][gc,heap                 ] GC(0) Heap before GC invocations=0 (full 0): def new generation   total 17856K, used 15936K [0x00000000c0000000, 0x00000000c1350000, 0x00000000d5550000)
...

К сожалению, это не похоже на связь, поскольку начинается после третьей паузы.

update 2020-04-26:

В OpenJDK 14 приложение использует 100% ЦП на моей (однопроцессорной) машине VirtualBox (работающей на ЦП i7-6600U). Виртуальная машина имеет 3,5 ГБ оперативной памяти. По словам диспетчера задач 40% + является свободным, а активность диска составляет 0% (я думаю, это означает, что нет подкачки). Добавление еще одного ЦП к виртуальной машине (и активация гиперпоточности для физических машин) делает приложение снова достаточно быстрым. Мне просто интересно, было ли это преднамеренным компромиссом во время разработки JDK с потерей производительности на (редких) однопроцессорных машинах, чтобы ускорить JVM на многоядерных / гиперпоточных процессорах?

Ответы [ 5 ]

6 голосов
/ 26 апреля 2020

Из моего опыта проблемы с производительностью JDK связаны в основном с одним из следующих факторов:

  • JIT-компиляция
  • Конфигурация виртуальной машины (размеры кучи)
  • G C алгоритм
  • Изменения в JVM / JDK, которые нарушают известные хорошо работающие приложения
  • (О, и я забыл упомянуть загрузку классов ...)

Если вы просто используете конфигурацию JVM по умолчанию, начиная с OpenJDK11, возможно, вам следует установить некоторые из наиболее заметных опций на фиксированные значения, такие как G C, Размер кучи и т. Д. c.

Возможно, какой-нибудь графический инструмент анализа может помочь отследить вашу проблему. Как Retrace, AppDynamics или FlightRecorder и тому подобное. Они дают более общий обзор общего состояния кучи, g c циклов, ОЗУ, потоков, загрузки ЦП и т. Д. В определенный момент времени, чем могут предоставить файлы журнала.

Правильно ли я понимаю, что ваше приложение пишет около 30710 строк в журнале в течение первой секунды работы (под OpenJDK11)? Почему он «только» пишет о 7k строк в OpenJDK14 в первую секунду? Мне кажется, это огромная разница для приложения, которое только что запущено на разных JVM ... Вы уверены, что, например, в журнал не помещено большое количество стековых трасс Exception?
Другие числа иногда даже выше, так может замедления связаны с регистрацией исключений? Или даже подкачки, если ОЗУ становится мало?
На самом деле я думаю, что если приложение ничего не записывает в журнал, это признак бесперебойной работы без проблем (если только в это время он не зависает полностью). То, что происходит со секунд 12-22 (в случае с OpenJDK14 здесь), это то, что меня больше беспокоит ... зарегистрированные строки go через крышу ... почему ?
И после этого ведение журнала сводится к минимальным значениям в 1-2k строк ... в чем причина , что ?? (ну, может быть, это g c, который включается в секунду 22 и выполняет табула раса, которая разрешает некоторые вещи ...?)

Другая вещь может быть вашим утверждением о «однопроцессорных» машинах. Означает ли это также «одно ядро» (ИДК, может быть, ваше программное обеспечение настроено на устаревшее оборудование или что-то в этом роде)? И виртуальные машины с одним процессором работают на этих машинах? Но я предполагаю, что я ошибаюсь из-за этих предположений, так как в настоящее время почти все процессоры являются многоядерными ... но я бы мог заняться проблемой многопоточности (взаимоблокировки), возможно.

5 голосов
/ 03 мая 2020

TL; DR : это регрессия OpenJDK.

Я не сделал ничего, кроме этого, но я мог воспроизвести проблему с простым привет миром:

public class Main {
    public static void main(String[] args) {
        System.out.println("Hello world");
    }
}

Я использовал эти два пакетных файла:

main-1cpu.bat, который ограничивает процесс java только одним процессором:

c:\windows\system32\cmd.exe /C start /affinity 1 \
    \jdk-14\bin\java \
    -Xlog:all=trace:file=app-1cpu.txt:uptime,tid,level,tags:filecount=50 \
    Main

main-full.bat, процесс java может использовать оба процессора:

c:\windows\system32\cmd.exe /C start /affinity FF \
    \jdk-14\bin\java \
    -Xlog:all=trace:file=app-full.txt:uptime,tid,level,tags:filecount=50 \
    Main

(Различия заключаются в значении affinity и имени файла журнала. Я обернул его для облегчения чтения, но обтекание \, вероятно, не работает на Windows.)

Несколько измерений Windows 10 x64 в VirtualBox (с двумя процессорами):

PS Z:\main> Measure-Command { .\main-1cpu.bat }

...    
TotalSeconds      : 7.0203455
...


PS Z:\main> Measure-Command { .\main-full.bat }

...
TotalSeconds      : 1.5751352
...


PS Z:\main> Measure-Command { .\main-full.bat }

...
TotalSeconds      : 1.5585384
...


PS Z:\main> Measure-Command { .\main-1cpu.bat }

...
TotalSeconds      : 23.6482685
...

Созданные журналы трассировки содержат похожие паузы, которые вы видите в вопросе.

Выполнение Main без трассировок происходит быстрее, но по-прежнему видна разница между версией с одним и двумя процессорами: ~ 4-7 секунд против ~ 400 мс.

I ' мы отправили эти результаты в hotspot-dev@openjdk список рассылки и разработчики подтвердили, что это то, что JDK может передать лучше . Вы также можете найти предполагаемых исправлений в ветке. Надеюсь, это будет исправлено в OpenJDK 15.

5 голосов
/ 26 апреля 2020

Поскольку он использует 100% ЦП "большую часть времени", и это занимает в 10 раз больше времени (!) При Java 14, это означает, что вы тратите 90% своего ЦП на Java 14.

Недостаточно места в куче может сделать это, поскольку вы проводите много времени в G C, но вы, кажется, исключили это.

I обратите внимание, что вы настраиваете смещенную блокировку, и она имеет существенное значение. Это говорит мне о том, что, возможно, ваша программа выполняет много параллельной работы в нескольких потоках. Возможно, в вашей программе есть ошибка параллелизма, которая появляется в Java 14, но не в Java 10. Это также может объяснить, почему добавление другого процессора делает его более чем в два раза быстрее.

Ошибки параллелизма часто появляются только в том случае, если вам не повезло, и триггер действительно мог быть чем угодно, например, изменение организации hashmap и т. д. c.

Во-первых, если это возможно, проверьте наличие циклов, которые могут быть Ожидание занято вместо сна.

Затем запустите профилировщик в режиме выборки (это сделает jvisualvm) и найдите методы, которые занимают гораздо больший% общего времени, чем следовало бы. Поскольку ваша производительность снижается в 10 раз, любые проблемы там действительно должны выпадать.

2 голосов
/ 27 апреля 2020

Это интересная проблема, и для ее сужения потребуется неопределенное количество усилий, поскольку существует множество перестановок и комбинаций, которые необходимо проверить, а также собрать и сопоставить данные.

Похоже, что в течение некоторого времени не было никакого разрешения. Возможно, это необходимо повысить.

РЕДАКТИРОВАТЬ 2: Поскольку «ThreadLocalHandshakes» устарела, и мы можем предположить, что блокировка разрешена, предложите попробовать без «UseBiasedLocking» ускорить этот сценарий.

Однако есть некоторые предложения по сбору дополнительных данных и попытке изолировать проблему.

  1. Выделить более одного ядра [Я вижу, что вы попробовали это, и проблема исчезла. Кажется, проблема с выполнением потока / ов, исключающая другие. См. № 7 ниже)
  2. Выделите больше кучи (возможно, требования v14 больше, чем требования более ранних jdks)
  3. Выделите больше памяти для Win 10 VB.
  4. Проверьте системные сообщения ОС (Win 10 в вашем случае)
  5. Запустите его в не виртуализированной Win 10.
  6. Попробуйте другую сборку jdk 14
  7. Делать поток дамп каждые (или профиль) несколько интервалов времени. Проанализируйте, какой поток работает исключительно. Возможно, есть настройка для справедливого распределения времени. Возможно, запущен поток с более высоким приоритетом. Что это за нить и что она делает? В linux вы можете отслеживать легкие процессы (потоки), связанные с процессом, и его состояние в реальном времени. Что-то похожее на Win 10?
  8. Загрузка процессора? 100% или меньше? Ограничен CPU или mem? 100% CPU в служебных потоках? Какой поток службы?
  9. Вы явно указали G C al go?

Я лично был свидетелем проблем в версиях, связанных с G C, изменением размера кучи, проблемами с виртуализированными контейнерами и т. Д.

Нет простого ответа на этот вопрос Я думаю, тем более, что этот вопрос существует уже некоторое время. Но мы можем постараться изо всех сил и сообщить нам, что является результатом некоторых из этих шагов изоляции.

РЕДАКТИРОВАТЬ 1: из обновленного вопроса, похоже, связано с G C или другим служебный поток принимает одно ядро ​​неравномерно (Thread-Local Handshakes)?

1 голос
/ 26 апреля 2020

Будьте осторожны с регистрацией на медленных дисках, это замедлит работу вашего приложения:

https://engineering.linkedin.com/blog/2016/02/eliminating-large-jvm-gc-pauses-caused-by-background-io-traffic

Но, похоже, причина не в этом проблемы, так как процессор все еще занят, и вам не нужно ждать, пока все потоки достигнут безопасной точки благодаря локальному рукопожатию: https://openjdk.java.net/jeps/312

Также нет непосредственно связана с вашей проблемой, но в более общем плане, если вы хотите попытаться увеличить производительность вашего оборудования во время запуска, взгляните на AppCDS (класс обмена данными):

https://blog.codefx.org/java/application-class-data-sharing/

...