Анализ журнала JAVA GC

Java

Вот пример Java8

Симуляция окружающей среды GC

Сначала мы даем следующий код для запуска GC

public static void main(String[] args) {
    // 每100毫秒创建100线程，每个线程创建一个1M的对象，即每100ms申请100M堆空间
    Executors.newScheduledThreadPool(1).scheduleAtFixedRate(() -> {
        for (int i = 0; i < 100; i++) {
            new Thread(() -> {
                try {
                    //  申请1M
                    byte[] temp = new byte[1024 * 1024];
                    Thread.sleep(new Random().nextInt(1000)); // 随机睡眠1秒以内
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
            }).start();
        }
    }, 1000, 100, TimeUnit.MILLISECONDS);
}

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

Логика программы: каждые 100 миллисекунд создается 100 потоков, и каждый поток создает объект размером 1M, то есть на каждые 100 мс применяется 100M пространства кучи. Причина, по которой каждый поток спит случайным образом в течение 1 с, заключается в том, чтобы предотвратить смерть объектов и гарантировать, что некоторые объекты могут быть переведены в старость, что может лучше запускать Young GC и Full GC.Обратите внимание, что если это время ожидания слишком велико, это вызовет OOM. Если он маленький, сложно запустить ПОЛНЫЙ GC.

Объяснение параметров виртуальной машины

Запустите процесс Java: java -Xms200m -Xmx200m -Xmn100m -verbose:gc -XX:+PrintGCDetails -Xloggc:./gc.log -XX:+PrintGCDateStamps -jar demo-0.0.1-SNAPSHOT.jar

-Xms200m -Xmx200m Мин./макс. память кучи 200M

-Xmn100m младшее поколение памяти 100M

-verbose:gc включить ведение журнала GC

-XX:+PrintGCDetails -Xloggc:./gc.log -XX:+PrintGCDateStamps Введите данные журнала GC в gc.log

jmap-анализ

jcmd получает идентификатор нашего Java-процесса: 6264.

jmap -heap 6264 Просмотр информации о куче

В первый раз, когда мы проверили, мы обнаружили, что площадь Эдема составляет 98 м, а S0 и S1 — 1 м.

Вторая проверка, площадь Эдема 99м, S0, S1 0.5м

Соотношение площади Эдема и площади Выживших меняется динамически, а не 8:1:1 по умолчанию.

Получается, что мы используем дефолтную комбинацию сборщика мусора Parallel Scavenge+Parallel Old, и под этим сборщиком по умолчанию включено -XX:+UseAdaptiveSizePolicy, то есть соотношение площади Эдема к площади Survivor будет адаптивно меняться в соответствии с Ситуация с ГК.

Добавляем параметры, отключаем адаптацию молодого поколения и устанавливаем соотношение молодого поколения 8:1:1

-XX:-UseAdaptiveSizePolicy -XX:SurvivorRatio=8

Кроме того, чтобы как можно быстрее запустить ПОЛНУЮ сборку мусора, мы добавили параметры виртуальной машины.

-XX:MaxTenuringThreshold=10

Возраст повышения изменен с 15 по умолчанию на 10, что упрощает переход объектов из молодого поколения в старое поколение.

Перезапустите виртуальную машину для просмотра jmap

молодое поколение

  • 80 миллионов в районе Эдема использовали 51 миллион, а текущий уровень использования составляет 63,8%

  • 10 млн в области S0 использовали 0,43 млн, коэффициент использования составляет 4,37%

  • Скорость использования области S1 10M пуста

старость

  • 100M использовали 18,39M, уровень использования 18,9%

Анализ содержимого журнала GC

Посмотрите на журнал GC gc.log, который мы выводим, и выберите два из них.

2019-06-09T02:55:30.993+0800: 330.811: [GC (Allocation Failure) [PSYoungGen: 82004K->384K(92160K)] 184303K->102715K(194560K), 0.0035647 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 2019-06-09T02:55:30.997+0800: 330.815: [Full GC (Ergonomics) [PSYoungGen: 384K->0K(92160K)] [ParOldGen: 102331K->5368K(102400K)] 102715K->5368K(194560K), [Metaspace: 16941K->16914K(1064960K)], 0.0213953 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]

Young GC

[GC (Allocation Failure) [PSYoungGen: 82004K->384K(92160K)] 184303K->102715K(194560K), 0.0035647 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

объяснять:

  • GC GC молодого поколения: [Pre-Pred Pred Production 80,08M-> GC 0.37M (общее количество молодого поколения 90 м)] GC Front Counce 179,98M-> GC 10,3 м (куча общего размера 190m), время]

  • Суммарный размер молодого поколения 90М вместо 100М. Тут я понимаю, что текущая максимальная заявка для молодого поколения 90М

  • 100M*80%=80M - это площадь Эдема.

  • 80M*80% = 64M Район Эдема по умолчанию занимает более 80%, то есть 64M вызовет YoungGC

Full GC

[Full GC (Ergonomics) [PSYoungGen: 384K->0K(92160K)] [ParOldGen: 102331K->5368K(102400K)] 102715K->5368K(194560K), [Metaspace: 16941K->16914K(1064960K)], 0.0213953 secs] [Times: user=0.02 sys=0.00, real=0.02 secs]

объяснять:

  • [Молодое поколение до GC 0.375M->Молодое поколение после GC 0M (общий размер молодого поколения 90M)][Старое поколение до GC 99.93M->Старое поколение после GC 5.24M (Общий размер старого поколения 100M)]Куча перед GC 100,3M -> После кучи GC 5,24M (общий размер кучи 190M), [область метаданных: 16,5 до GC, 16,5 после GC (общий размер области метаданных 1040M)], использованное время]

  • Можно предположить, что причиной этого FullGC является отсутствие места для продвижения молодого поколения к старому поколению.

Анализ с помощью инструментов визуализации

Здесь мы используемgceasy.io/Проанализируйте это

(1) Подсчитайте молодое поколение, старое поколение, а также максимальное свободное пространство и пиковое значение области метаданных.Здесь размер области метаданных не настроен в параметрах нашей виртуальной машины, поэтому значение по умолчанию составляет 1040 МБ.

(2) Статистика пропускной способности, средней задержки GC, максимальной задержки и интервала задержки

(3) Анализ размера кучи в режиме реального времени, красная позиция показывает, что произошел FullGC, что привело к резкому падению общей кучи.

Вы обнаружите, что виртуальная машина запускает большое количество ПОЛНЫХ сборщиков мусора вскоре после запуска. Насколько я понимаю, объекты, к которым мы обращаемся, случайно засыпают в течение одной секунды, и большинство из них все еще имеют ссылки на потоки, когда они только что запущены, и GCRoot доступен. Запуск FULL GC в начале запуска не полностью очищает пространство старого поколения и постоянно запускает FULL GC из-за нехватки места.

(4) Статистика общего объема пространства и времени GC

(5) Различное время GC, время GC, общее количество GC и другие индикаторы

Суммировать

Анализ журнала сборщика мусора может помочь нам макроскопически отслеживать операции сборщика мусора. С одной стороны, если частый FullGC будет иметь серьезные проблемы с производительностью (STW), с другой стороны, если GC слишком частый, то есть GC занимает большую долю нормальной работы системы и пропускная способность низкий, что в определенной степени является пустой тратой ресурсов производительности. Если в системе есть проблема с производительностью, согласно анализу GC различных показателей в качестве эталона, мы также можем внести некоторые коррективы в параметры программы или виртуальной машины.

Категории