Tomcat прерывистые замедления, не отвечает, зависает
Я пытался отследить причину прерывистого замедления работы нашего сервера Tomcat. Мы получаем замедления несколько раз в неделю, когда Tomcat перестает отвечать на запросы или занимает несколько минут для обработки запросов, а процессор загружается в окно (Linux), как показывает время безотказной работы, обычно с 1-2 до 30. Затем все постепенно работает само собой, и через 10 минут или около того все приходит в норму.
Мы используем Apache в качестве внешнего интерфейса и Postgres для нашей базы данных. Я копался в журналах, чтобы попытаться выяснить, что может быть причиной проблемы. Я не заметил каких-либо явных увеличений спроса во времена замедления.
Я обнаружил, что во многих случаях, прямо перед замедлением, Tomcat, похоже, просто ложится спать в течение примерно трех с половиной минут. За это время в его журналах нет записей и нет запросов от Tomcat к базе данных. После небольшого перерыва Tomcat просыпается и начинает яростно пытаться обработать все резервные копии за это время, что приводит к большой загрузке базы данных и процессора, а также к медленному времени отклика.
Чтобы попытаться выяснить, что Tomcat делает во время сна, я настроил скрипт для мониторинга его журнала и отправил сигнал kill -3, чтобы получить дамп потока, если в журнале не было никаких действий в течение трех минут. К сожалению, сигнал не разбудит Tomcat, поэтому дамп потока не происходит до тех пор, пока он сам не проснется и не возобновит обработку.
Apache и Postgres, по-видимому, все еще не спят и активны в течение трех с половиной минут - их журналы показывают, что активность, не связанная с Tomcat, продолжается в течение этих периодов.
Наша версия Tomcat - 5.0.28.
Мысли, предложения? Я довольно новичок в работе с Tomcat, поэтому, пожалуйста, не принимайте много знаний.
После активации подробной сборки мусора в соответствии с предложением Алекса я обнаружил пару случаев возникновения проблемы и обнаружил, что за это отвечает Full GC, что в обоих случаях заняло более 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]
Теперь мне просто нужно выяснить, как настроить вещи, чтобы предотвратить это. (Предложения приветствуются.)
Спасибо за помощь, Алекс и Mainguy.
3 ответа
Первый шаг, как указано выше, состоит в том, чтобы изменить стартовый скрипт tomcat для добавления
-verbose:gc -XX:+PrintGCTimeStamps -XX:+PrintGCDetails
Если у вас есть замедление, ищите в catalina.out такие вещи, как "FullGC" или множество GC...
Я хотел бы заметить, что если вы еще этого не сделали, увеличьте размер кучи tomcat где-то в пределах от 1/2 до 3/4 доступной памяти, предполагая, что это окно JUST запускает tomcat. Например, чтобы установить максимальную кучу в 768 мегабайт, вы должны добавить:
-Xmx768M
в JAVA_OPTS
Если вы используете Ubuntu 10.04, эти настройки обычно находятся в /etc/default/tomcat6.
Это произошло, когда хороший кусок памяти в "постоянном" поколении кучи Java был выгружен на диск, потому что это мусор, и он давно не использовался. Когда требуется полная коллекция, эту память необходимо вернуть обратно.
В этом случае ваш ответ несколько нелогичен: УМЕНЬШИТ размер кучи Java или выясните, какие другие вещи используют ОЗУ, которое вызывает перестановку. В нашем случае некоторые ночные пакетные задания использовали кучу оперативной памяти, в результате чего старое поколение было выгружено на диск. Итак, первый полный GC, необходимый на следующее утро, занял FOREVER (более 180 секунд, сколько вы видите).
Вы также можете попробовать очиститель с одновременной отметкой, который сокращает время полного GC, выполняя большую часть работы параллельно. Это лучшая документация, которую я видел; Есть также несколько хороших блогов Sun по этой теме: http://www.oracle.com/technetwork/java/gc-tuning-5-138395.html
Попробуйте активировать многословную сборку мусора и посмотрите, не приостановилась ли сборка мусора. Я предполагаю, что огромная куча, большое количество объектов и своп могут вызвать долгую паузу, но это звучит довольно необычно.