Я пытался отследить причину периодических замедлений работы нашего сервера Tomcat. Мы получаем замедления несколько раз в неделю, когда Tomcat перестает отвечать или обрабатывает запросы несколько минут, а загрузка процессора в поле (Linux), как показывает время безотказной работы, резко возрастает с 1-2 до более 30. Затем все постепенно проходит само, и все возвращается в норму примерно через 10 минут.
Мы используем Apache в качестве интерфейса и Postgres для нашей базы данных. Я копался в журналах, чтобы попытаться выяснить, что может быть причиной проблемы. Я не заметил очевидного увеличения спроса во время спада.
Я обнаружил, что несколько раз, незадолго до замедления, Tomcat, кажется, просто засыпал примерно на три с половиной минуты. В это время в его журналах нет записей и нет запросов от Tomcat к базе данных. После небольшого сна Tomcat просыпается и начинает яростно пытаться обработать все данные, которые были зарезервированы за это время, что приводит к тяжелой загрузке базы данных и процессора и медленному времени отклика.
Чтобы попытаться выяснить, что делает Tomcat во время дремоты, я настроил сценарий для отслеживания его журнала и отправки сигнала kill -3 для получения дампа потока, если в журнале не было никакой активности в течение трех минут. К сожалению, сигнал не пробуждает Tomcat, поэтому дамп потока не происходит до тех пор, пока он не проснется сам по себе и не возобновит обработку.
Apache и Postgres, очевидно, все еще бодрствуют и активны в течение трех с половиной минутных перерывов - их журналы показывают, что в эти периоды продолжается активность, не связанная с Tomcat.
Наша версия Tomcat - 5.0.28.
Мысли, предложения? Я новичок в работе с Tomcat, поэтому, пожалуйста, не предполагайте особых знаний.
После активации подробной сборки мусора по предложению Алекса я зафиксировал несколько случаев возникновения проблемы и обнаружил, что за это отвечает полный сборщик мусора, который в обоих случаях занимает более 200 секунд, например:
04:21:55.648491500 [GC 1035796K->933637K(1041984K), 0.3407580 secs]
04:21:56.012832500 [Full GC[Unloading class sun.reflect.GeneratedMethodAccessor633]
04:22:38.003920500 [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor39]
04:22:38.004051500 [Unloading class sun.reflect.GeneratedConstructorAccessor102]
04:22:38.004392500 [Unloading class sun.reflect.GeneratedConstructorAccessor98]
04:22:38.004533500 [Unloading class sun.reflect.GeneratedSerializationConstructorAccessor40]
04:22:38.004716500 [Unloading class sun.reflect.GeneratedMethodAccessor634]
04:22:38.004808500 [Unloading class sun.reflect.GeneratedConstructorAccessor90]
04:22:38.004889500 [Unloading class sun.reflect.GeneratedConstructorAccessor95]
04:22:38.005044500 [Unloading class sun.reflect.GeneratedMethodAccessor632]
04:25:18.688916500 933637K->154281K(1041984K), 202.6760940 secs]
Теперь мне просто нужно выяснить, как все настроить, чтобы этого не произошло. (Предложения приветствуются.)
Спасибо за помощь, Алекс и Мэнги.
Шаг первый, как указано выше, состоит в том, чтобы изменить сценарий запуска tomcat, чтобы добавить
-verbose:gc -XX:+PrintGCTimeStamps -XX:+PrintGCDetails
Когда у вас замедление, ищите вещи в catalina.out как "FullGC" или многие GC ...
Я хотел бы отметить, что если вы еще этого не сделали, увеличьте размер кучи tomcat примерно до 1/2 - 3/4 доступной памяти, предполагая, что этот блок ПРОСТО запускает tomcat. Например, чтобы установить максимальную кучу на 768 мегабайт, вы должны добавить:
-Xmx768M
к JAVA_OPTS
Если вы используете ubuntu 10.04, эти настройки обычно находятся в / etc / default / tomcat6.
У нас такое случалось, когда хороший кусок памяти в «постоянном» поколении кучи Java был выгружен на диск, потому что это мусор и какое-то время не использовался. Когда требуется полная коллекция, эту память необходимо вернуть обратно.
В этом случае ваш ответ несколько противоречит интуиции: УМЕНЬШИТЕ размер кучи Java или выясните, какие еще вещи используют ОЗУ, вызывая подкачку. В нашем случае для некоторых ночных пакетных заданий использовалось много оперативной памяти, в результате чего старое поколение выгружалось на диск. Итак, первый полный сборщик мусора, необходимый на следующее утро, занял НАВСЕГДА (180+ секунд, как вы видите).
Вы также можете попробовать сборщик параллельных меток, который сокращает время полного сборщика мусора, выполняя большую часть работы параллельно. Это лучшая документация, которую я видел; Есть также несколько хороших блогов Sun по этой теме: http://www.oracle.com/technetwork/java/gc-tuning-5-138395.html
Попробуйте активировать подробную сборку мусора и посмотрите, не приостановлена ли сборка мусора. Я предполагаю, что огромная куча, много выделения объектов и обмена могут вызвать долгую паузу, но это звучит довольно необычно.