Ахаха, HotSpot, що ти робиш, припини!

       
 
 Як ви напевно вже знаєте , скоро в Пітері пройде чергова конференція Joker . Я збираюся зробити на ній доповідь про те, як розслідувати поведінку JVM, позірна спочатку таємничим і загадковим. Цей пост — тизер, призначений для того, щоб дати вам можливість зрозуміти, чого чекати від доповіді.
 
Припустимо, що до вас раптом приходить інформація про проблему: при збірці сміття відображуються причини «Last Ditch Collection» і «No GC» , і пошук в інтернеті не дає нічого зрозумілого. На щастя, HotSpot практично повністю збирається з OpenJDK, і тому, як мінімум в теорії, ми можемо знайти відповіді на всі цікаві для нас питання прямо в исходниках. Чим ми і займемося!
 
 
 Last Ditch Collection Озброївшись вихідним кодом OpenJDK , пошукаємо цікаву для нас рядок:
 
 
$ grep -irn "Last Ditch Collection" .
./src/share/vm/gc_interface/gcCause.cpp:94:      return "Last ditch collection";

Зайдемо в файл і виявимо там відсилання до
_last_ditch_collection
— елементу
enum
, яке містить всі можливі причини збірки сміття. Відразу ж підгляне і потрібну константу для «No GC», їй виявиться
_no_gc
. Продовжимо Грепан:
 
 
$ grep -rn "GCCause::_last_ditch_collection" .
...
./src/share/vm/gc_implementation/shared/vmGCOperations.cpp:286:        heap->collect_as_vm_thread(GCCause::_last_ditch_collection);
...

 
Схоже, що це воно! Почитавши метод , в якому знаходиться виклик, і особливо — його коментарі, ми досить швидко розуміємо, що відбувається.
 
По всій видимості, коли HotSpot не може виділити місце для чогось, що повинно знаходитися в metaspace (наприклад, для класу), спершу запускається збірка сміття з причиною
GCCause::_metadata_GC_threshold
. Якщо це не допомагає, то проводиться спроба розширити metaspace. Якщо і це не допомагає, то запускається повна збірка сміття з причиною
GCCause::_last_ditch_collection
. Під час цієї збірки підчищаються soft references. Якщо навіть це не допомагає, то тоді місце дійсно скінчилося, і пора кидати OOM.
 
Звучить правдоподібно, але варто навчитися стабільно це відтворювати. Якщо вірити написаному вище, то при активному засмічуванні metaspace ми повинні побачити як мінімум одну збірку з причиною «Last ditch collection»:
 
 
ClassPool pool = ClassPool.getDefault();
for(long l = 0; l < Long.MAX_VALUE; l++) {
    pool.makeClass("com.example.Kitty" + l).toClass();
}

Якщо це запустити з параметрами за замовчуванням, то чекати доведеться досить довго. Але ми можемо зменшити розмір metaspace і отримати результат швидше:
 
 
$ java -cp build/libs/labs-8-all.jar -XX:+PrintGCDetails -XX:MaxMetaspaceSize=10m ru.gvsmirnov.perv.labs.gc.NoGcTrigger
...
[Full GC (Last ditch collection) [...] 14470K->14425K(32768K), [Metaspace: 8971K->8971K(1056768K)], 0.0481030 secs]
...
Exception in thread "main" javassist.CannotCompileException: by java.lang.OutOfMemoryError: Metaspace
    at javassist.ClassPool.toClass(ClassPool.java:1099)
    ...

 
У більшості випадків ми побачимо більш, ніж одну збірку з причиною «last ditch collection». Це цілком очікувано, оскільки інакше б від них не було толку, і навряд чи б цю фічу взагалі реалізували.
 
До речі, тут ми дивилися на исходники Java 9, але логіка last ditch collection не змінювалася дуже давно, так що тут турбуватися нема про що.
 
Ще одна кумедна річ, яку варто згадати: нам, в общем-то, і не потрібно було писати коду, активно ГаДя в metaspace. Та й взагалі будь-якого коду: адже JVM і сама горазда позагружать класи. Якщо ми просто запустимо
java -XX:+PrintGCDetails -XX:MaxMetaspaceSize=2m X
, то отримаємо кілька разів last ditch collection, а потім і OOM. Віртуальна машина навіть не встигне зрозуміти, що класу
X
не існує.
 
 No GC Перейдемо до «No GC». Капітан підказує нам, що розробники HotSpot навряд чи б назвали так нормальну причину збірки сміття. Та й взагалі, єдиний випадок, в якому ми, за логікою, повинні таке побачити — це якщо ми встигнемо запустити jstat раніше, ніж станеться хоч одна збірка сміття:
 
 
$ jstat -gccause -t `jps | grep NoGc | cut -d' ' -f1` 100

Timestamp     S0     S1      E      O      P    YGC     YGCT   FGC     FGCT      GCT     LGCC     GCC
      0.7   0.00   0.00   4.00   0.00  40.34      0    0.000     0    0.000    0.000    No GC   No GC
      0.8   0.00   0.00   6.00   0.00  45.82      0    0.000     0    0.000    0.000    No GC   No GC
      0.9   0.00   0.00   6.00   0.00  51.44      0    0.000     0    0.000    0.000    No GC   No GC

Або якщо він зробить перевірку, коли збирач сміття не активний:
 
 
Timestamp     S0     S1      E      O      P    YGC     YGCT   FGC     FGCT      GCT                 LGCC     GCC
      2.8   0.00   0.00   0.00   0.78  31.00      5    0.080     5    1.051    1.131   Allocation Failure   No GC

 
Так що, якщо це було виявлено в іншій ситуації, то це, мабуть, баг. А оскільки коли ми розбирали last ditch collection, таких дивацтв не спостерігалося, то є шанс того, що він вже виправлений. Проявимо трохи оптимізму і пошукаємо всі підходящі коммітов:
 
 
$ hg grep --all '::_no_gc'
...
src/share/vm/gc_implementation/shared/vmGCOperations.cpp:2097:+:  assert(((_gc_cause != GCCause::_no_gc) &&
...

 
Ага! Схоже, що проблему дійсно пофиксили в Ком номер 2097 , ще в лютому 2013 року. Зазирнувши в файл hotspot_version , ми виявляємо, що остання HotSpot, в якій повинна спостерігатися проблема — це 21.0-b01 . У мене під рукою була Java 6 з версією HotSpot 20.45-b01 :
 
 
$ java -version
java version "1.6.0_45"
Java(TM) SE Runtime Environment (build 1.6.0_45-b06)
Java HotSpot(TM) 64-Bit Server VM (build 20.45-b01, mixed mode)

 
При запуску нашого прикладу з котиками, негайно виходить наступний результат:
 
 
Timestamp     S0     S1      E      O      P    YGC     YGCT   FGC     FGCT      GCT                 LGCC                     GCC
      2.7   0.00   0.00   0.00   0.78 100.00      5    0.080     5    1.051    1.131      unknown GCCause      Allocation Failure
      2.8   0.00   0.00   0.00   0.78 100.00      5    0.080     5    1.051    1.131      unknown GCCause      Allocation Failure

 
Це досить близько, але не зовсім те, що ми шукали. Однак, при більш детальному вивченні патча стає очевидним, що потрібно просто використовувати інший збирач сміття. Додавання
-XX:+UseG1GC
дасть нам потрібний результат:
 
 
Timestamp     S0     S1      E      O      P    YGC     YGCT    FGC    FGCT      GCT                  LGCC                        GCC
      1.6      ?      ?      ?      ?  96.78      ?        ?     ?        ?        ?   G1 Evacuation Pause                      No GC
      1.7      ?      ?      ?      ? 100.00      ?        ?     ?        ?        ?   No GC                Permanent Generation Full
      1.8      ?      ?      ?      ? 100.00      ?        ?     ?        ?        ?   No GC                Permanent Generation Full
      1.9      ?      ?      ?      ? 100.00      ?        ?     ?        ?        ?   No GC                Permanent Generation Full
      2.0      ?      ?      ?      ? 100.00      ?        ?     ?        ?        ?   No GC                Permanent Generation Full

 
Успіх! До речі, той чоловік, який першим відповість, чому тут якісь знаки питання, і що саме має навести нас на використання G1, отримає запрошення на Joker Unconference;)
 
 Післямова Отже, щойно, на підставі одного-єдиного твіту і використовуючи базові утиліти командного рядка, ми відповіли на НЕ гуглящійся питання, знайшли стародавній баг в HotSpot, змогли завдяки цьому оцінити зверху версію JVM, і навіть дізналися, який використовувався збирач сміття.
 
Мораль проста: HotSpot — не якась загадкова шайтан-машина. В світі взагалі немає нічого загадкового, воно є лише у нас в головах .
 
P.S. Якщо у вас є цікавий приклад з цієї опери, то не соромтеся надсилати його. Цілком можливо, що я розберу його в доповіді, або навіть просто так :)
 
P.P.S. На конференцію приїде кілька запрошених спікерів, які не знають російської мови. вони будуть раді, якщо буде більше доповідей англійською. Я додав опитування, щоб зрозуміти, як до такого може поставитися основна частина слухачів.

  
Джерело: Хабрахабр

0 коментарів

Тільки зареєстровані та авторизовані користувачі можуть залишати коментарі.