Странное поведение GC приложения актеров Scala - PullRequest
Новая
       18

Странное поведение GC приложения актеров Scala

9 голосов
/ 02 февраля 2010

У меня приложение, которое использует довольно много актеров : 25 000, если быть точным. Он использует Scala 2.7.7 и работает на jdk6_u18 . Он в основном слушает и обрабатывает рыночные данные и имеет очень небольшое состояние.

Он начинается в 8.02 утра каждый день, и в течение часа он падает с OutOfMemoryError. «Ага, - говорите вы, - у вас утечка памяти!» За исключением того, что, когда я перезапускаю его, он никогда , когда-либо снова падает на весь оставшийся день! И это несмотря на увеличение нагрузки на ГХ и ЦП, когда рынки США открываются в 14:30.

Несколько анекдотических выводов:

  • он работает на Solaris. Когда я запускал его в Linux, он никогда не падал вообще .
  • Я пробовал возиться с определением размера кучи для генерации, выделять больше памяти и т.д.
  • Поведение коллектора, кажется, отличается, когда у меня verbose:gc включен

Возникают несколько вопросов:

  1. Почему поведение этой программы может отличаться в Linux и Solaris?
  2. Почему было бы иначе поведение, начиная с 8.02 и начиная с 8.42?
  3. Я слышал, что в библиотеке актеров были проблемы с утечкой памяти. Кем они были, когда их исправили и как я узнал, что здесь может происходить что-то «похожее»? (Что нужно искать в jhat и т. Д.)
  4. Кто-нибудь имеет представление о том, что может происходить?

Я сейчас пытаюсь G1 узнать, имеет ли это какое-то значение. Я обновлю этот вопрос завтра!

Некоторый вывод из G1 с многословным: gc on

Кажется, я только что понял это:

600,290: [Полная GC 255M-> 144M (256M), 1,5772616 секунд]
602,084: [GC пауза (молодые) 227M-> 145M (256M), 0,0556769 с]
602,418: [Полный GC 254M-> 144M (256M), 1,6415216 с]
604,279: [пауза GC (молодые) 227M-> 145M (256M), 0,0415157 с]
604.602: [Полная ГХ 255М-> 145М (256М), 1,6041762 с]
606,422: [GC пауза (молодые) 227M-> 145M (256M), 0,0237441 с]
606,710: [Полный GC 254M-> 145M (256M), 1,6022185 с]

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

849,084: [Полный GC 254M-> 176M (256M), 1,9658754 с]
851,191: [GC пауза (молодые) 228M-> 176M (256M), 0,0218611 с]
851,414: [Полный GC 254M-> 176M (256M), 1,9352357 с]
853,492: [GC пауза (молодые) 228M-> 176M (256M), 0,0224688 с]
853,716: [Полный GC 254M-> 176M (256M), 1,9339705 секунд]
855,793: [GC пауза (молодые) 228M-> 176M (256M), 0,0215707 с]
856,009: [Полная GC 254M-> 176M (256M), 1,9805797 с]
858,137: [GC пауза (молодые) 228M-> 176M (256M), 0,0223224 секунды]

Некоторый вывод из G1 с подробным текстом: gc off

Это снова хорошо! * Вздох *

303,656: [пауза GC (молодые) 225M-> 93M (256M), 0,1680767 с]
308,060: [GC пауза (молодые) 226M-> 94M (256M), 0,1793724 с]
312,746: [GC пауза (молодые) 227M-> 93M (256M), 0,1674851 с]
316.162: [пауза GC (молодой) 227M-> 95M (256M), 0,1826145 с]
320,147: [GC пауза (молодые) 226M-> 94M (256M), 0,1656664 секунды]
325,978: [GC пауза (молодые) 226M-> 93M (256M), 0,1475760 с]
330,176: [GC пауза (молодые) 226M-> 94M (256M), 0,1727795 с]

и много, много позже все еще в порядке!

25882,894: [пауза GC (молодые) 224M-> 125M (256M), 0,2126515 с]
25884,880: [GC пауза (молодые) 224M-> 126M (256M), 0,2059802 с]
25887,027: ​​[GC пауза (молодые) 224M-> 125M (256M), 0,1851359 с]
25889,940: [GC пауза (молодые) 223M-> 126M (256M), 0,2046496 с]
25891,567: [GC пауза (молодые) 224M-> 126M (256M), 0,1600574 с]

и позже, полный GC

37180.191: [пауза GC (младшая) 225M-> 154M (256M), 0,1716404 с]
37182.163: [пауза GC (молодая) (начальная отметка) 225M-> 153M (256M) 37182,326: [одновременная GC-mark-start], 0,1622246 с]
37183,089: [Конец одновременной отметки GC, 0,7635219 с]
37183,090: [Замечание GC, 0,0032547 с]
37183,093: [запуск одновременного подсчета GC]
37183.297: [Конец одновременного подсчета ГХ, 0,2043307]
37183,393: [Очистка ГХ 198M-> 198М (256М), 0,0068127 с]
37183.400: [Запуск одновременной очистки ГХ]
37183,400: [Конец одновременной очистки GC, 0,0000393]
37183,648: [Пауза GC (молодая) 222M-> 153M (256M), 0,1483041 с]
37184.235: [Пауза GC (частичная) 171M-> 91M (256M), 0,2520714 секунд]
37187,223: [GC пауза (молодые) 221M-> 92M (256M), 0,1721220 секунд]

ОБНОВЛЕНИЕ

Хорошо, так как переключение наG1 сборщик мусора на jdk1.6.0_18 приложение вело себя три дня подряд.Я подозреваю, что Эрик прав в своем анализе ситуации о том, что ВМ попадает в спираль смерти в случаях с высокой пропускной способностью, когда она продвигает объекты в штатное поколение.

Ответы [ 3 ]

4 голосов
/ 03 февраля 2010

Есть ли у вас основания ожидать, что ваша куча будет медленно увеличиваться в размерах? Похоже, в обоих следах он растет. Одна вещь, которую я сделал во многих случаях, - это уменьшить кучу, чтобы попытаться усугубить проблему. Однако 256M - это нижний предел для Scala.

Одна вещь, которую я заметил раньше, это то, что если у вас есть недолговечные объекты, которые делают его из поколения Эдема из-за слишком большого давления, он может постепенно убить вас. Это может произойти, когда есть всплеск активности (может быть, у вас есть взрыв по утрам?) И ваше пространство не достаточно велико. Scala в целом и актеры в частности интенсивно используют небольшие недолговечные объекты, и кажется, что существует этот магический порог, когда вы пересекаете все это вниз по склону. Так что один прогон будет в порядке, а следующий вылетает и горит.

Еще одна вещь, которую я заметил раньше, это то, что настройки GC, которые хорошо работают в OSX / x86, часто не работают в Sparc / Solaris и наоборот. Если вы используете CoolThreads, я предлагаю вам настроить GC так, чтобы в вашем планировщике / пуле был один поток GC на каждый поток.

Что поднимает еще одну вещь - убедитесь, что планировщик не создает новые потоки волей-неволей. Это будет делать это иногда. Я бы сказал, что вы почти всегда должны вручную устанавливать колпачок на темы. Я не знаю, насколько это актуально, но интересный факт о планировщике fork-join, который актеры используют по умолчанию, заключается в том, что он предназначен для коротких задач, связанных с процессором. Делая IO в потоках, он управляет ошибками своих предположений. Конечно, это все еще должно работать, но ...

Удачи! Я потерял много-много дней своей жизни из-за таких проблем.

Взгляните на некоторые варианты здесь: http://java.sun.com/performance/reference/whitepapers/tuning.html

Похоже, вы используете коллектор одновременной метки-развертки. Попробуйте установить: 

-XX:+UseParallelGC
1 голос
/ 02 февраля 2010

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

0 голосов
/ 25 сентября 2011

С моей точки зрения компоновка кучи неверна.Старое пространство варьируется от 93М в начале до 176 при высокой нагрузке.как я вижу из журналов, у вас есть генерация в среднем около 50 МБ / с.Таким образом, если у вас есть пауза около 2 секунд на полный gc в точке 176 МБ, у вас не будет молодого пространства для создания новых объектов.Мои советы:

  • Проверьте настройки мест выживших - ваше старое пространство увеличивается до 176M.сокращение нового пространства - очевидно, это не намеренно

  • Установите NewSize явно на желаемое значение, скажем 128M

  • увеличить общий размер кучи для продвижения объектов вместоfull gc

  • у вас очень длинные паузы: gc 80 МБ> 50 мс, ~ 120 МБ> 150 мс.Вместо этого попробуйте CMS, я думаю, что это будет быстрее. (Но сделайте тесты)
...