почему длинный ParNew GC только с очень большим временем использования? - PullRequest
Новая
       23

почему длинный ParNew GC только с очень большим временем использования?

2 голосов
/ 10 июля 2019

Я запускаю приложение Java в контейнере (с k8s) и обнаружил длинный STW gc: 

2019-07-10T16:45:31.081+0800: 1620992.943: [GC (Allocation Failure) 2019-07-10T16:45:31.082+0800: 1620992.944: [ParNew: 1232340K->105476K(1258304K), 0.0558525 secs] 1412255K->290236K(4054528K), 0.0571538 secs] [Times: user=0.23 sys=0.20, real=0.06 secs] 
2019-07-10T16:46:08.906+0800: 1621030.767: [GC (Allocation Failure) 2019-07-10T16:46:08.907+0800: 1621030.768: [ParNew: 1224004K->97149K(1258304K), 5.4008859 secs] 1408764K->286575K(4054528K), 5.4022113 secs] [Times: user=37.65 sys=0.00, real=5.41 secs] 
2019-07-10T16:46:48.426+0800: 1621070.287: [GC (Allocation Failure) 2019-07-10T16:46:48.426+0800: 1621070.288: [ParNew: 1215677K->106022K(1258304K), 0.0545431 secs] 1405103K->300294K(4054528K), 0.0557196 secs] [Times: user=0.41 sys=0.00, real=0.06 secs]

Второй GC восстановил почти тот же объем памяти (1,1 ГБ) по сравнению с егопредыдущий и следующий сборщик мусора, затрачивая при этом значительное количество времени (5,4 секунды).Это связано с очень высоким пользовательским временем в ParNew GC.

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

Моя версия Java: 

$ java -version
java version "1.8.0_102"
Java(TM) SE Runtime Environment (build 1.8.0_102-b14)
Java HotSpot(TM) 64-Bit Server VM (build 25.102-b14, mixed mode)

И потоки GC из jstack: 

"Concurrent Mark-Sweep GC Thread" os_prio=0 tid=0x00007f3be809b000 nid=0xb5 runnable 
"Gang worker#0 (Parallel GC Threads)" os_prio=0 tid=0x00007f3be801d000 nid=0xab runnable 
"Gang worker#1 (Parallel GC Threads)" os_prio=0 tid=0x00007f3be801f000 nid=0xac runnable 
"Gang worker#2 (Parallel GC Threads)" os_prio=0 tid=0x00007f3be8020800 nid=0xad runnable 
"Gang worker#3 (Parallel GC Threads)" os_prio=0 tid=0x00007f3be8022800 nid=0xae runnable 
"Gang worker#4 (Parallel GC Threads)" os_prio=0 tid=0x00007f3be8024800 nid=0xaf runnable 
"Gang worker#5 (Parallel GC Threads)" os_prio=0 tid=0x00007f3be8026000 nid=0xb0 runnable 
"Gang worker#6 (Parallel GC Threads)" os_prio=0 tid=0x00007f3be8028000 nid=0xb1 runnable 
"Gang worker#7 (Parallel GC Threads)" os_prio=0 tid=0x00007f3be802a000 nid=0xb2 runnable 
"Surrogate Locker Thread (Concurrent GC)" #4 daemon prio=9 os_prio=0 tid=0x00007f3be812d800 nid=0xb9 waiting on condition [0x0000000000000000]
"Gang worker#0 (Parallel CMS Threads)" os_prio=0 tid=0x00007f3be8097000 nid=0xb3 runnable 
"Gang worker#1 (Parallel CMS Threads)" os_prio=0 tid=0x00007f3be8099000 nid=0xb4 runnable

1 Ответ

0 голосов
/ 12 июля 2019

Реальное время - время стены, то есть сколько времени фактически прошло.Пользовательское время - это циклы ЦП, агрегированные по всем ядрам, проведенным в пользовательском пространстве, выполняющим работу.Поскольку у вас есть 8 параллельных потоков GC, это просто означает, что большая часть этих 5 секунд была потрачена на большинство ядер, выполняющих работу по сбору.

Само по себе это ничего не говорит нам о том, почему это заняло столько времени.Насколько мне известно, мало что можно сделать, чтобы получить больше информации из ParNew, это очень простой сборщик.Вы можете переключиться на G1, который предоставляет гораздо более подробные журналы.

Понимание пауз GC в JVM, второстепенный GC HotSpot от Алексея Рагозина разбит на тайм-аут ParNew.

Выможет также захотеть отслеживать вашу систему на предмет конфликтов ЦП / ввода-вывода / подкачки (например, путем ведения журнала / proc / pressure / * с метками времени в текущих ядрах Linux), которые могут замедлить работу сборщика мусора.

...