По Java GC спецы есть? Это вообще реально?

[timeau]

Отцы,
Вопрос на очень много. Есть база, в которую через Scala (считайте, что Java)-based loader загружаются гигабайты данных. Это не формула речи, общий объем базы ~40 млрд записей. Нет, мы не следим ни за кем, мы мирные Но не суть. На веб-морде самой базы рисуется вот такая картинка.

before.png

То есть лоадер реально работает 2 минуты, а 10 минут занимается херней.
Я спросил коллегу, что писАл его, что это такое, поскольку последний раз сам лично использовал Жабу в 99-м году. Он ответил, что фигня вопрос, ща поправлю. И поправил вот так:

after.png

На мой недоуменный вопрос, что это вообще, он ответил, что заменил garbage collector: старый, дескать, останавливал все приложение и собирал память, а новый делает это in background.
Как видно из картинки, все равно полный швах, хоть и стало лучше: две минуты работаем, пять - курим бамбук.
Вопросов два:
1. Это реально так? Я всю жизнь на C/C++/Perl, сейчас вот Питон, потому для меня все это как минимум дико.
2. Что можно предпринять? Ну не переписывая лоадер с нуля на Python/C++, уже сроки дымятся.

Заранее благодарю.

[Vоvan]

2.4% RAM - это оно столько себе определяет? Я бы процессу(сам) распределил дохрена памяти - 2/3 например если больше ничего на VM нету.

А GC - да, с ним можно много играть и результаты будут разные.

[alex5]

Причем здесь вообще "жаба" и  мусоросборщик? График обработки данных и загрузки совпадает с графиком хттп запросов, видимо откуда данные и поступают. Что смущает то?

[timeau]

2.4% RAM - это оно столько себе определяет?

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

А GC - да, с ним можно много играть и результаты будут разные.

То есть 2 минуты работы (но там несколько миллионов записей за эти 2 минуты грузятся) и 10 минут сборки мусора - это нормально? В смысле - обычно? Не что-то из ряда вон выходящее?

Причем здесь вообще "жаба" и  мусоросборщик? График обработки данных и загрузки совпадает с графиком хттп запросов, видимо откуда данные и поступают. Что смущает то?

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

[Vоvan]

хм... давно это было

А нельзя количество threads поднять - видно когда запросов много время обработки растет немеряно - вродже thread-ится оно должно само по себе. (Я правда scala не знаю как настраивать)

Из своего опыта я в такой ситуации принудительно процесу давал море памяти и увеличивал количество max thread - все масштабировалось без увеличения вермени на запрос.

Еще он может в profiler загнать и посмотреть что с обьектами происходит - может чтот не убирается вовремя.

--
V.

[Vоvan]

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

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

--
В.

[timeau]

А нельзя количество threads поднять - видно когда запросов много время обработки растет немеряно

Там и так порядка 30 тредов шарашит. А "горбы" на желтом левом графике - это как раз нужный мне throughput, до сотни на первом графике доходит.

Из своего опыта я в такой ситуации принудительно процесу давал море памяти и увеличивал количество max thread - все масштабировалось без увеличения вермени на запрос.

Время запроса нормальное, проблема не в нем. А в том, что после двух минут работы лоадер прекращает слать запросы к базе (второй зеленый график): он тупо мусор собирает. И так 10 минут.

[alex5]

А в том, что после двух минут работы лоадер прекращает слать запросы к базе (второй зеленый график): он тупо мусор собирает. И так 10 минут.

Если только у вас хип не 100Гб, сбор мусора занимает в хушем случае секунды, даже со 100ГБ минуты бы не набралось, болъше похоже на нехватку ресурсов по сети или типа IO wait.

[timeau]

Если только у вас хип не 100Гб,

На ноде 16 ГБайт и 4 ЦП. Таких нодов 2. Это где лоадер крутится.

сбор мусора занимает в хушем случае секунды, даже со 100ГБ минуты бы не набралось,

Хорошо, тогда почему так поменялась картина при замере garbage collector? Вон вторая картинка на это прямо указывает. Это не холивар вести, уважаемый, тут все проиллюстрировано. И Ваши "секунды" - да 600 секунд - тоже "секунды".

болъше похоже на нехватку ресурсов по сети или типа IO wait.

Ну да, ну да, у Гугла в облаке плохая сеть.
Какой IO Wait? У кого? У лоадера? А почему он запросы не шлет на базу? Второй зеленый график видели?

[alex5]

Если только у вас хип не 100Гб,

На ноде 16 ГБайт и 4 ЦП. Таких нодов 2. Это где лоадер крутится.

сбор мусора занимает в хушем случае секунды, даже со 100ГБ минуты бы не набралось,

Хорошо, тогда почему так поменялась картина при замере garbage collector? Вон вторая картинка на это прямо указывает. Это не холивар вести, уважаемый, тут все проиллюстрировано. И Ваши "секунды" - да 600 секунд - тоже "секунды".

болъше похоже на нехватку ресурсов по сети или типа IO wait.

Ну да, ну да, у Гугла в облаке плохая сеть.
Какой IO Wait? У кого? У лоадера? А почему он запросы не шлет на базу? Второй зеленый график видели?

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

[Palych]

Надобно найти 3 графика изнутри JVM (сейчас много мониторов для этого есть, jconsole еще не выкинули из jdk? есть jstat по-моему, он в тексте представляет информацию):
* Heap size
* GC calls per minute or other period
* Percent of time spent in GC

Я бы предложил эксперимент на шару: уменьшить размер кучи раз в 10 и посмотреть будут ли заморозки. Такое бывает когда памяти выделено гораздо больше чем приложению нужно. А практически все сборщики что я помню сидят на попе ровно пока процент свободной памяти не опустится ниже определенной отметки (30% вроде по умолчанию)

Проблема действительно генетическая для жабы: полное отсутствие управления памятью со стороны кода в сочетании с многопоточностью, когда все потоки имеют полностью равноправный доступ к одной и той же куче. В результате ресурсы нужно тратить не только на сборку мусора, но и на поиск мусора.
Но проблема решаемая в принципе: я видел (правда очень издалека) приложение, которое отрабатывало RT запросы для очень, очень, очень больших решений в области коммуникаций.

[timeau]

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

Не пишите тут больше, хорошо? Уровень Вашего профессионализма уже понятен.

Я бы предложил эксперимент на шару: уменьшить размер кучи раз в 10 и посмотреть будут ли заморозки. Такое бывает когда памяти выделено гораздо больше чем приложению нужно. А практически все сборщики что я помню сидят на попе ровно пока процент свободной памяти не опустится ниже определенной отметки (30% вроде по умолчанию)

Палыч, благодарю!
Попробую потрясти разработчика, авось что и выйдет. У меня нет непосредственной власти над ним, но кое-что можно придумать.

[tessob]

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

Не пишите тут больше, хорошо? Уровень Вашего профессионализма уже понятен.

Я склонен согласиться с alex5. Судя по графикам у вас корреляция графиков DATA & HTTP практически единица. Они просто отмасштабированы по разному. И судя по цифрам на них у вас далеко не high-load.

[Palych]

То есть 2 минуты работы (но там несколько миллионов записей за эти 2 минуты грузятся) и 10 минут сборки мусора - это нормально?

Кстати, я это пропустил, думал наоборот.
Не хочу тебя пугать, но "тут какая-то страшная тайна", не просто неоптимальные настройки...
Я видел нечто подобное когда в JBoss поломался механизм кеширования, и он на каждом запросе распаковывал довольно солидный архив в память, читал что-то маленькое и тут же всё выкидывал в мусор.
Возможно там тоже очень большая утечка памяти...
В общем - удачи вам!

[Palych]

Кстати, надобно ещё CPU usage смотреть, особенно в момент когда она бамбук курит.

[timeau]

Судя по графикам у вас корреляция графиков DATA & HTTP практически единица. Они просто отмасштабированы по разному. И судя по цифрам на них у вас далеко не high-load.

В этом и дело! То есть лоадер перестает посылать эти HTTP запросы. То есть он ничего полезного не делает. В этом и проблема. Кластер стоит спокойный и незагруженный. Да, возможно это неочевидно: HTTP запросы идут на вход, так сказать. Это не customers' requests, по HTTP входные данные закачиваются.

Возможно там тоже очень большая утечка памяти...

Вот почему-то я в этом совершенно не сомневаюсь...
Хуже то, что я сам считай что не могу в код залезть: ну в смысле могу, залезу, нормально понимаю, что это и как работает. Но нет у меня жабьих знаний и опыта для отлизывания таких тонкостей. Увы и ах. В "плюсах" все проще и привычнее.

Кстати, надобно ещё CPU usage смотреть, особенно в момент когда она бамбук курит.

Фигачит только в путь, только шуба заворачивается...

[tessob]

В этом и дело! То есть лоадер перестает посылать эти HTTP запросы. То есть он ничего полезного не делает. В этом и проблема. Кластер стоит спокойный и незагруженный. Да, возможно это неочевидно: HTTP запросы идут на вход, так сказать. Это не customers' requests, по HTTP входные данные закачиваются.

Не уверен, что я корректно Вас понял, но если у вас метрики DATA & HTTP снимаются с базы и HTTP это просто протокол общения с базой, то первое, чтобы я сделал это взял бы какой нибудь микрометр и вкорячил бы в контроллеры сервиса подсчет числа входящих запросов. Если корреляция сохранится, то значит проблема не на стороне сервиса. Если у сервиса входящий трафик будет выражен более плоским графиком, то тогда надо смотреть где идет потеря производительности. В этом случае можно будет взять какой-нибудь профилировщик, который умеет во флейм-чарты по ЦПУ и памяти, чтобы понять где именно проблема. Если корреляция сохранится, то проблема в самом трафике.

Что касается ГЦ, то если вы используете жабу 8+ и запускаете ее с дефолтными настройками ГЦ, то скорее всего проблема не в нем. Современные ГЦ уже давно избавились от проблем начала нулевых и уж тем более конца девяностых. Если вы не разматывается огромные XML загружая их как DOM, то вряд ли у вас задержки выходят за пределы нескольких микросекунд, и уж точно не больше секунды.

Вообще есть старая максима -- чтобы что-то улучшить это что-то сначала нужно измерить.

[timeau]

Не уверен, что я корректно Вас понял, но если у вас метрики DATA & HTTP снимаются с базы и HTTP это просто протокол общения с базой, то первое, чтобы я сделал это взял бы какой нибудь микрометр и вкорячил бы в контроллеры сервиса подсчет числа входящих запросов.

Не уверен, что понимаю, зачем это. Есть веб-морда базы (см. картинку), есть Графана, там такое же кол-во входящих соединений.

Если вы не разматывается огромные XML загружая их как DOM, то вряд ли у вас задержки выходят за пределы нескольких микросекунд, и уж точно не больше секунды.

Видите ли, если бы мы спорили о преимуществе iPhone vs Android, то такие, мягко скажем, пропагандистские лозунги типа "за пределы нескольких микросекунд", "точно не больше секунды", я бы понял и простил, как говорится. У меня вопрос: Вы изначальный пост, самый первый, читали? Или увидели знакомы слова и ринулись в бой?
Давайте я напомню: вторая картинка - это то же самое, тот же программный самый код, но с другим ГК. Задержки уменьшились до 5 минут, потому что доподлинно известно, что новый ГК работает в background, а не останавливает приложение полностью. Нагрузка у нас steady, один и тот же формат данных, один и тот же размер batch'a.
Вы по-прежнему насчет микросекунд будете настаивать? Или все-таки оторвемся от вымышленного мира, где сферические единороги в вакууме катают на себе пукающих фиалками принцесс?

[iDesperado]

скала конечно любит идемпотентность и плодить объекты, но у меня тоже сомнение, что такого рода аппликухи могут перегрузить gc. на машинке с 16gb залипнуть на минуты, не верится, но раз уж подозреваешь gc то рассказывай версию jvm и имя gc, далее сразу врубай лог, что-то типа
-Xlog:gc,safepoint:gc.log:time,uptime,level,tags:filecount=1,filesize=100M

после чего надо врубать несколько threads на gc
https://docs.oracle.com/cd/E40972_01/do ... tm#autoId2

[timeau]

скала конечно любит идемпотентность и плодить объекты, но у меня тоже сомнение, что такого рода аппликухи могут перегрузить gc. на машинке с 16gb залипнуть на минуты, не верится, но раз уж подозреваешь gc то рассказывай версию jvm и имя gc, далее сразу врубай лог, что-то типа
-Xlog:gc,safepoint:gc.log:time,uptime,level,tags:filecount=1,filesize=100M

после чего надо врубать несколько threads на gc
https://docs.oracle.com/cd/E40972_01/do ... tm#autoId2

Ценно, спасибо!

но у меня тоже сомнение, что такого рода аппликухи могут перегрузить gc. на машинке с 16gb залипнуть на минуты, не верится

Я ведь с этого и начал: такое вообще возможно? И, судя по второй картинке, где поменяли исключительно ГК, это "ж-ж-ж!" неспроста. В общем, буду приседать на мозги разработчику. Хотя там пока пальцем не ткнешь непосредственно в баг, будет, как в том анекдоте: "Винни, Винни! А куда это я пошел?!"

[Palych]

А что там со свопом?
Много ли его используется?

[iDesperado]

Я ведь с этого и начал: такое вообще возможно? И, судя по второй картинке, где поменяли исключительно ГК, это "ж-ж-ж!" неспроста.

врубить gc лог пятиминутное дело и программист для этого не нужен. через 7 минут у тебя уже все ответы будут. и назови уже версию jvm и что за gc.

[timeau]

и назови уже версию jvm и что за gc.

Code: Select all

JAVA_VERSION=jdk-11.0.18+10
-XX:+UseG1GC

[iDesperado]

Code: Select all

JAVA_VERSION=jdk-11.0.18+10
-XX:+UseG1GC

почему тогда поведение поменялось ? G1 дефолтный для jdk 11 и -XX:+UseG1GC и параметр бессмыслен.

[timeau]

почему тогда поведение поменялось ? G1 дефолтный для jdk 11 и -XX:+UseG1GC и параметр бессмыслен.

А вот теперь я вовсе ничего не понимаю. Я "присел" на девелопера, и он признался, что сначала вообще в командной строке ничего не указывал, а потом дописал "-XX:+UseG1GC".
Получается, ГК вообще не при делах? Ох ты ж блин...