JVM internals - what does the JVM do? — Ian Rogers

[Palych]

Не знаю как там у Павла, но по моим наблюдениям нагруженная система часто реагирует на "толчки" извне (типа резкого, пусть даже кратковременного замедления) достаточно ошутимо: некоторые запросы замедляются на десятки секунд, даже если толчёк длился менее секунды.
Впрочем - таких толчков в нашей системе слишком много чтобы достоверно говорить о корелляции.
Кстати - 4 секунды это одно из самых больших наблюдаемых full GC time. иногда и за 150ms управляется. Думаю если ужать размер кучи, можно достигнуть ещё большей гладкости. Однако стрёмно: ежели толчёк будет сильный (не GC, а например downstream systems slow down) - есть риск нарваться на OOM и прочие ужосы.

[crypto5]

Не знаю как там у Павла

Извините заработался

, но по моим наблюдениям нагруженная система часто реагирует на "толчки" извне (типа резкого, пусть даже кратковременного замедления) достаточно ошутимо: некоторые запросы замедляются на десятки секунд, даже если толчёк длился менее секунды.

Это какая то неправильная ситуация, наверное можно что-то пофиксить.

[Flash-04]

вот типичная запись из лога:

Code: Select all

[Full GC 
INFO   | jvm 2    | 2012/07/20 13:38:45 |  2073454K->1544062K(6239040K), 6.0521510 secs]

[Flash-04]

обычный GC занимает обычно менее 0.1с, делается раз в минуту.
Full GC делается раз в час, видимо по расписанию.

[crypto5]

вот типичная запись из лога:

Code: Select all

[Full GC 
INFO   | jvm 2    | 2012/07/20 13:38:45 |  2073454K->1544062K(6239040K), 6.0521510 secs]

Ну и непонятно на сколько на самом деле оно останавливает мир, может на 0.01с, а все остальное время апликуха спокойно работает, только с загруженым процессором.

[crypto5]

Full GC делается раз в час, видимо по расписанию.

Мне кажется не по рассписанию, а когда обычного не хватает что бы освободить достаточно памяти

[Flash-04]

из логов это непонятно, но! обычно в этом логе каждую секунду что-то пишется (там дофига статистики), а в эти 6 секунд ничего между в этом промежутке не появилось. почему?

[crypto5]

из логов это непонятно, но! обычно в этом логе каждую секунду что-то пишется (там дофига статистики), а в эти 6 секунд ничего между в этом промежутке не появилось. почему?

А у вас какой GC? CMS?

[Flash-04]

Мне кажется не по рассписанию, а когда обычного не хватает что бы освободить достаточно памяти

нет! когда памяти не хватает, там появляются совсем другие записи, типа "memory allocation in red zone" тогда full GC может инициироваться каждые несколько минут, пока либо память не осободится, либо апликуха не помрет от истощения

[Flash-04]

А у вас какой GC? CMS?

скажу если расскажите как это понять

[rzen]

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

[Flash-04]

расписания конечно нет

видимо приложение само его инициирует:

Code: Select all

INFO   | jvm 2    | 2012/07/20 03:37:35 | [Full GC
INFO   | jvm 2    | 2012/07/20 04:37:41 | [Full GC
INFO   | jvm 2    | 2012/07/20 05:37:48 | [Full GC
INFO   | jvm 2    | 2012/07/20 06:37:54 | [Full GC
INFO   | jvm 2    | 2012/07/20 07:38:00 | [Full GC
INFO   | jvm 2    | 2012/07/20 08:38:06 | [Full GC
INFO   | jvm 2    | 2012/07/20 09:38:13 | [Full GC
INFO   | jvm 2    | 2012/07/20 10:38:19 | [Full GC
INFO   | jvm 2    | 2012/07/20 11:38:26 | [Full GC
INFO   | jvm 2    | 2012/07/20 12:38:32 | [Full GC
INFO   | jvm 2    | 2012/07/20 13:38:38 | [Full GC

[Palych]

вот типичная запись из лога:

Code: Select all

[Full GC 
INFO   | jvm 2    | 2012/07/20 13:38:45 |  2073454K->1544062K(6239040K), 6.0521510 secs]

Ну и непонятно на сколько на самом деле оно останавливает мир, может на 0.01с, а все остальное время апликуха спокойно работает, только с загруженым процессором.

Кстати, я вроде бы видел свидетельства того, что хотя бы что-то таки продолжает работать во время full GC. Но возможно это были погрешности измерений...

[crypto5]

А у вас какой GC? CMS?

скажу если расскажите как это понять

Concurrent Mark & Sweep -XX:+UseConcMarkSweepGC

[Flash-04]

вот такое нашел, видимо всё же живет:

Code: Select all

INFO   | jvm 2    | 2012/07/20 03:37:35 | [Full GC
INFO   | jvm 2    | 2012/07/20 03:37:37 | [Unloading class sun.reflect.GeneratedMethodAccessor813]
INFO   | jvm 2    | 2012/07/20 03:37:37 | [Unloading class sun.reflect.GeneratedMethodAccessor814]
INFO   | jvm 2    | 2012/07/20 03:37:40 |  2005079K->1531110K(6239040K), 5.9037160 secs]

[rzen]

расписания конечно нет

видимо приложение само его инициирует:

Code: Select all

INFO   | jvm 2    | 2012/07/20 03:37:35 | [Full GC
INFO   | jvm 2    | 2012/07/20 04:37:41 | [Full GC
INFO   | jvm 2    | 2012/07/20 05:37:48 | [Full GC
INFO   | jvm 2    | 2012/07/20 06:37:54 | [Full GC
INFO   | jvm 2    | 2012/07/20 07:38:00 | [Full GC
INFO   | jvm 2    | 2012/07/20 08:38:06 | [Full GC
INFO   | jvm 2    | 2012/07/20 09:38:13 | [Full GC
INFO   | jvm 2    | 2012/07/20 10:38:19 | [Full GC
INFO   | jvm 2    | 2012/07/20 11:38:26 | [Full GC
INFO   | jvm 2    | 2012/07/20 12:38:32 | [Full GC
INFO   | jvm 2    | 2012/07/20 13:38:38 | [Full GC

приложение может взвести флаг, который JVM может обслужить а может и нет

http://docs.oracle.com/javase/6/docs/ap ... em.html#gc()

Runs the garbage collector.
Calling the gc method suggests that the Java Virtual Machine expend effort toward recycling unused objects in order to make the memory they currently occupy available for quick reuse. When control returns from the method call, the Java Virtual Machine has made a best effort to reclaim space from all discarded objects.

обратите внимание на выделенное слово.

[Flash-04]

Concurrent Mark & Sweep -XX:+UseConcMarkSweepGC

это принудительно надо включать? в настройках JVM такого ключа не вижу.

[Flash-04]

обратите внимание на выделенное слово.

обратил. в реальности похоже что работает такой запрос.

[rzen]

угу. обычно да, но даёт осечку в самое неудобное время

[crypto5]

Concurrent Mark & Sweep -XX:+UseConcMarkSweepGC

это принудительно надо включать? в настройках JVM такого ключа не вижу.

Вроде да. Насколько я понимаю сайд эфект может быть в том что этот товарищ будет захватывать все ядра, а обычный только одно, зато stop the world паузы должны быть значительно короче.

[Palych]

Full GC делается раз в час, видимо по расписанию.

Мне кажется не по рассписанию, а когда обычного не хватает что бы освободить достаточно памяти

Действительно, при определённых full gc случается каждый час. Честно говоря, не уверен от чего это зависит - он настроек или от наргузки...

[Palych]

Code: Select all

    -server \
    -Xmx2g \
    -Xms2g \
    -Xnoclassgc \
    -XX:PermSize=300m \
    -XX:MaxPermSize=300m \
    -XX:NewSize=800m \
    -XX:MaxNewSize=800m \
    -XX:+DisableExplicitGC \
    -XX:+UseParNewGC \
    -XX:+CMSParallelRemarkEnabled \
    -XX:+UseConcMarkSweepGC \
    -XX:-UseBiasedLocking \
    -XX:LargePageSizeInBytes=256m \

[Montchik]

Full GC делается раз в час, видимо по расписанию.

Мне кажется не по рассписанию, а когда обычного не хватает что бы освободить достаточно памяти

Действительно, при определённых full gc случается каждый час. Честно говоря, не уверен от чего это зависит - он настроек или от наргузки...

GC случается, когда почти вся память использована ! Minor в случае young generation и major - когда tenured generation истощилась. Давал жеж ужеж линк на неплохую статью на эту тему: http://www.oracle.com/technetwork/java/ ... 40523.html Посмотрите, может найдете как вашу беду побороть.

У вас освобождается всего 25% от используемого (2,073,454K->1,544,062K) Может подсыпать немного памяти tenured generation?
Еще можно попросить jvm выдавать доп инфу о gc: -XX:+PrintGCDetails
Еще наверное стоит попросить jvm игнорировать System.gc() и потестить: -XX:+DisableExplicitGC

[Palych]

GC случается, когда почти вся память использована !

Отнюдь.

[rzen]

GC случается, когда почти вся память использована !

Отнюдь.

именно. собссно вся суть эргономики в том, чтобы найти подмножество объектов которые можно освободить поскорее, не дожидаясь ООМ. гипотеза (эвристика) что молодые объекты с большОй вероятностью долго не живут себя отлично оправдала.