Здравствуйте!

Иногда (примерно раз в день-два) наш продуктовый сервер "падает". И вот уже несколько месяцев не могу понять почему. Ни одной записи ни в один лог сервер не пишет. На момент падения процессор не загружен.

Когда сервер упал пару дней назад, я сделал дам потоков (через kill -3). Вот ссылка на дамп: дамп потоков

Я написал утилиту, которая разбирает дамп, и смотрит, какие блокировки наиболее ожидаемые. Нашел, что есть 5 таких блокировок, которых ожидает более одного потока. Причем ожидают долго, потому что потоки растут несколько минут перед тем, как tomcat вообще перестанет отдавать страницы.

Одна из этих пяти блокировок (0x00002b58afb89630) нигде не лочится в дампе потоков (нету locked <0x00002b58afb89630>), но 85 потоков ее ожидают. Как это может быть???

Другие 4 лока залочены потоками, которые "залипают" на примитивных операциях на длительное время. Например, этот поток сейчас находится в
java.util.HashMap.newKeyIterator, но 89 других потоков ждут этого лока (<0x00002b58afb85b1>) несколько минут:

"http-8080-Processor1533" daemon prio=1 tid=0x00002aaab2566160 nid=0x6acb runnable 
 
[0x000000004c410000..0x000000004c412c20]
    at java.util.HashMap.newKeyIterator(HashMap.java:889)
    at java.util.HashMap$KeySet.iterator(HashMap.java:921)
    at java.util.HashSet.iterator(HashSet.java:154)
    at net.sf.ehcache.event.RegisteredEventListeners.notifyElementExpiry(RegisteredEventListeners.java:116)
    at net.sf.ehcache.Cache.remove(Cache.java:1017)
    at net.sf.ehcache.Cache.searchInMemoryStore(Cache.java:829)
    at net.sf.ehcache.Cache.get(Cache.java:654)
    - locked <0x00002b58afb85b18> (a net.sf.ehcache.Cache)
    at org.hibernate.cache.EhCache.get(EhCache.java:75)
    at org.hibernate.cache.StandardQueryCache.get(StandardQueryCache.java:96)
    at org.hibernate.loader.Loader.getResultFromQueryCache(Loader.java:2086)
    ....................................
    at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
    at java.lang.Thread.run(Thread.java:595)

Остальные 3 лока тоже залипли на примитивных операциях.

Вот что выдала моя утилита, которая анализирует количество вхождений waiting to lock <xxx> и waiting on <xxx> в лог.

waiting to lock <xxx>::
<0x00002b58afb8bd18>: 1 times.
<0x00002b58afb9aa50>: 1 times.
<0x00002b58afb9c138>: 2 times.
<0x00002b58afb8b690>: 1 times.
<0x00002b597ae1ecf8>: 1 times.
<0x00002b58afb85b18>: 89 times.
<0x00002b58afb88548>: 1 times.
<0x00002b58afb96110>: 1 times.
<0x00002b58afb89630>: 85 times.
<0x00002b58afb8e5a0>: 1 times.
<0x00002b58afb98090>: 1 times.
<0x00002b58afbacd28>: 1 times.
<0x00002b58afb99380>: 1 times.
<0x00002b58afb9a0f8>: 1 times.
<0x00002b58afb90d48>: 1 times.
<0x00002b58a34127a8>: 4 times.
<0x00002b58b09c5138>: 29 times.
<0x00002b58afb91d18>: 1 times.
 
waiting on <xxx>::
<0x00002b58afbb0370>: 1 times.
<0x00002b58adae0ff8>: 1 times.
<0x00002b58adae0f48>: 1 times.
<0x00002b58adae0d38>: 1 times.
<0x00002b58afbb0518>: 1 times.
<0x00002b58adae0de8>: 1 times.
<0x00002b58af9a7ba0>: 1 times.
<0x00002b58adae0e98>: 1 times.
<0x00002b58afbaf898>: 1 times.
<0x00002b58b0930400>: 1 times.
<0x00002b58afbaff00>: 1 times.

Моя системная конфигурация:

jdk 1.5.0.11
tomcat 5.5.20
SuSe Linux 10.1

Как я могу решить эту проблему? Пожалуйста, помогите мне!

Спасибо!

При следующем падении нужно сделать 2 дампа с интервалом в 1-2 минуты

Если второй дамп будет показывать, что поток "http-8080-Processor1533", который захватил монитор <0x00002b58afb85b18>, по прежнему находится в состоянии runnable и все еще находится в java.util.HashMap.newKeyIterator(HashMap.java:889), то тогда пробему нужно искать в net.sf.ehcache.Cache. Но вполне может быть, что просто мгновенный срез потоков застал такую ситуацию, когда много потоков обратились к кешу, один из них захватил монитор и начал проходить по большому HashSet итератором. Возможно, через несколько секунд картина будет другой.

Проблема с монитором <0x00002b58b09c5138> аналогично первой — поток "http-8080-Processor1602" находится в состоянии runnable в java.util.HashMap.newKeyIterator, остальные ждут его

возможно, кэш слишком большой? Вам не известно, сколько элементов находится в этих HashSet?

Что касается монитора <0x00002b58afb89630>, действительно странно, опять можно сделать два дампа потоков и сравнить их, не было ли каких то изменений. Проблема происходит из-за java.util.prefs.AbstractPreferences. Какой наследник его используется в org.apache.jetspeed.om.preference.impl.PrefsPreferenceSetImpl?

Здравствуйте, igor.r, Вы писали:

IR>возможно, кэш слишком большой? Вам не известно, сколько элементов находится в этих HashSet?

Если сложить все ячейки для кеша из конфигурационного файла — получится 10 430 элементов. Памяти для томката выделено 4 Гб. Вы думаете, ее может быть недостаточно?

Здравствуйте, VetalB, Вы писали:

VB>Здравствуйте, igor.r, Вы писали:

IR>>возможно, кэш слишком большой? Вам не известно, сколько элементов находится в этих HashSet?

VB>Если сложить все ячейки для кеша из конфигурационного файла — получится 10 430 элементов. Памяти для томката выделено 4 Гб. Вы думаете, ее может быть недостаточно?


1. нет ... я думаю сколько времени занимает проход итератором по множеству с 10430 элементов?
2. как насчет того, очем я писал — сделать 2 или 3 дампа потоков с интервалом в 1 минуту? Это позволит понять, завис ли поток или просто долго выполняется?