Почему "упал" мой java-сайт? (есть дамп потоков)
От: VetalB  
Дата: 14.06.07 07:36
Оценка:
Всем здравствуйте!

Ситуация такая.

Сегодня ночью упал наш java-сайт. Симптомы были такие: при попытке запросить любую страницу tomcat очень долго пытался ее загрузить, и страницу так и не отдавал. В логах (catalina.out и прочие) ничего при этом не писалось.

Сделал дамп потоков в это время: 214 разных потоков ждали лок <0x00002aaab9e0c260> в состоянии BLOCKED. Поток, который забрал этот лок залип в состоянии RUNNABLE на операции java.util.LinkedHashMap.createEntry.

Вот этот поток:

"http-8080-Processor536" daemon prio=10 tid=0x00002aabbe780400 nid=0x7d3e runnable [0x0000000051d43000..0x0000000051d44d20]
   java.lang.Thread.State: RUNNABLE
    at java.util.LinkedHashMap.createEntry(Unknown Source)
    at java.util.LinkedHashMap.addEntry(Unknown Source)
    at java.util.HashMap.put(Unknown Source)
    at net.sf.ehcache.store.MemoryStore.put(MemoryStore.java:107)
    - locked <0x00002aaab9e0c3f0> (a net.sf.ehcache.store.LruMemoryStore)
    at net.sf.ehcache.Cache.put(Cache.java:569)
    - locked <0x00002aaab9e0c260> (a net.sf.ehcache.Cache)
    at net.sf.ehcache.Cache.put(Cache.java:522)
    at org.hibernate.cache.EhCache.put(EhCache.java:120)
    at org.hibernate.cache.StandardQueryCache.put(StandardQueryCache.java:81)
    at org.hibernate.loader.Loader.putResultInQueryCache(Loader.java:2119)
    at org.hibernate.loader.Loader.listUsingQueryCache(Loader.java:2063)
    at org.hibernate.loader.Loader.list(Loader.java:2021)
    at org.hibernate.loader.criteria.CriteriaLoader.list(CriteriaLoader.java:95)
    at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1562)
    at org.hibernate.impl.CriteriaImpl.list(CriteriaImpl.java:283)
    at net.liga.persistence.dao.NewsDao.updateList(NewsDao.java:597)
    at net.liga.persistence.dao.NewsDao.find(NewsDao.java:396)
    at net.liga.rss.RssGenerator.getItemsList(RssGenerator.java:283)
    at net.liga.rss.RssGenerator.getChannel(RssGenerator.java:172)
    at net.liga.rss.RssGenerator.generateRss(RssGenerator.java:128)
    at net.liga.rss.RssGeneratorServlet.doGet(RssGeneratorServlet.java:55)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:689)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:802)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:252)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:173)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:213)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:178)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:126)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:105)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:107)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:148)
    at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:869)
    at org.apache.coyote.http11.Http11BaseProtocol$Http11ConnectionHandler.processConnection(Http11BaseProtocol.java:664)
    at org.apache.tomcat.util.net.PoolTcpEndpoint.processSocket(PoolTcpEndpoint.java:527)
    at org.apache.tomcat.util.net.LeaderFollowerWorkerThread.runIt(LeaderFollowerWorkerThread.java:80)
    at org.apache.tomcat.util.threads.ThreadPool$ControlRunnable.run(ThreadPool.java:684)
    at java.lang.Thread.run(Unknown Source)


Вот информация о хипе из дампа потоков:

Heap
 PSYoungGen      total 947840K, used 665728K [0x00002aab622f0000, 0x00002aabaeb10000, 0x00002aabb7840000)
  eden space 665728K, 100% used [0x00002aab622f0000,0x00002aab8ad10000,0x00002aab8ad10000)
  from space 282112K, 0% used [0x00002aab9c830000,0x00002aab9c830000,0x00002aabadbb0000)
  to   space 289920K, 0% used [0x00002aab8ad10000,0x00002aab8ad10000,0x00002aab9c830000)
 PSOldGen        total 2796224K, used 2796222K [0x00002aaab7840000, 0x00002aab622f0000, 0x00002aab622f0000)
  object space 2796224K, 99% used [0x00002aaab7840000,0x00002aab622ef9c0,0x00002aab622f0000)
 PSPermGen       total 112704K, used 112401K [0x00002aaaae240000, 0x00002aaab5050000, 0x00002aaab7840000)
  object space 112704K, 99% used [0x00002aaaae240000,0x00002aaab50047d8,0x00002aaab5050000)


Здесь видно, что OldGen и PermGen использованы на 99%, при этом в лог так и не выдавалось никаких ошибок (ни OutOfMemory, ни PermGen space error, ничего).

Вот ссылка на полный стекдамп: stackdump

Используемые технологии:

Java 6u1
Tomcat 5.5.20
SuSe Linux 10.1



Помогите пожалуйста разобраться, что произошло? И как устранить, чтобы больше это не повторялось...

Заранее большое спасибо!
Re: Почему "упал" мой java-сайт? (есть дамп потоков)
От: Blazkowicz Россия  
Дата: 14.06.07 08:16
Оценка:
Здравствуйте, VetalB, Вы писали:

Очевидно грабли либо в самом EhCache либо в его конфигурации.
Re[2]: Почему "упал" мой java-сайт? (есть дамп потоков)
От: VetalB  
Дата: 21.06.07 09:02
Оценка:
Здравствуйте, Blazkowicz, Вы писали:

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


B>Очевидно грабли либо в самом EhCache либо в его конфигурации


А почему именно EhCache? Там же затык происодит при вызове стандартного java-метода java.util.LinkedHashMap.createEntry.

Меня настораживает, что Eden и OldGen забиты на 99 процентов, правда в логах нигде нет сообщения об утечках памяти... Может, все таки есть утечка памяти???
Re[3]: Почему "упал" мой java-сайт? (есть дамп потоков)
От: Blazkowicz Россия  
Дата: 21.06.07 09:30
Оценка:
Здравствуйте, VetalB, Вы писали:

VB>А почему именно EhCache? Там же затык происодит при вызове стандартного java-метода

VB>java.util.LinkedHashMap.createEntry.

Потому что монитор <0x00002aaab9e0c260> был захвачен именно в EhCache:

at net.sf.ehcache.Cache.put(Cache.java:569)
- locked <0x00002aaab9e0c260> (a net.sf.ehcache.Cache)
at net.sf.ehcache.Cache.put(Cache.java:522)


А java.util.LinkedHashMap.createEntry это просто то место где был рантайм когда был произошел дамп.
Re[4]: Почему "упал" мой java-сайт? (есть дамп потоков)
От: VetalB  
Дата: 21.06.07 09:55
Оценка:
Здравствуйте, Blazkowicz, Вы писали:

B>А java.util.LinkedHashMap.createEntry это просто то место где был рантайм когда был произошел дамп.


А в стек-дампе рантайм находится в этом createEntry и через продолжительное время, то почему это может происходить? Означает ли это, что поток зашел в этот метод и не вышел из него? Если да, то при чем здесь EhCache?
Re[5]: Почему "упал" мой java-сайт? (есть дамп потоков)
От: Blazkowicz Россия  
Дата: 21.06.07 12:28
Оценка:
Здравствуйте, VetalB, Вы писали:

VB>А в стек-дампе рантайм находится в этом createEntry и через продолжительное время, то почему это может происходить? Означает ли это, что поток зашел в этот метод и не вышел из него? Если да, то при чем здесь EhCache?

Возможно этот метод там в цикле вызывается для огромного числа объектов. Вот дапмп на него всегда и показывает.
 
Подождите ...
Wait...
Пока на собственное сообщение не было ответов, его можно удалить.