Hi,
For several months we have been having out of memory errors every 2 weeks on one of our applications.
The symptoms are always the same: everything works normally (for several days) until suddenly memory gets consumed very quickly to the point that the VM gets an Out Of Memory Error.
For instance, here is the memory consumption during the last incident:
- 8:50:07 140Mb
- 8:50:12 312Mb
- 8:50:19 514Mb
- 8:50:29 835Mb
- 8:50:48 938Mb
...
After hours spent searching the cause, we finally got our hands on the following elements. It always happens when:
- an hql query plan gets created
- for a query that contains a IN. the number of elements in the IN being potentially high (between 0 and 1000)
For instance, here is a dump from the last incident:
Code:
"[ACTIVE] ExecuteThread: '17' for queue: 'weblogic.kernel.Default (self-tuning)'" id=146 idx=0x274 tid=35532 prio=5 alive, daemon
at jrockit/vm/Allocator.allocObject(Allocator.java:735)[optimized]
at sun/reflect/GeneratedConstructorAccessor127.newInstance([Ljava/lang/Object;)Ljava/lang/Object;(Unknown Source)
at sun/reflect/DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)[optimized]
at java/lang/reflect/Constructor.newInstance(Constructor.java:494)[optimized]
at java/lang/Class.newInstance0(Class.java:350)[inlined]
at java/lang/Class.newInstance(Class.java:303)[optimized]
at org/hibernate/hql/ast/SqlASTFactory.create(SqlASTFactory.java:211)
at antlr/ASTFactory.create(ASTFactory.java:153)[inlined]
at antlr/ASTFactory.create(ASTFactory.java:161)[inlined]
at org/hibernate/hql/ast/HqlSqlWalker.generateNamedParameter(HqlSqlWalker.java:786)[optimized]
at org/hibernate/hql/antlr/HqlSqlBaseWalker.parameter(HqlSqlBaseWalker.java:4537)[optimized]
at org/hibernate/hql/antlr/HqlSqlBaseWalker.expr(HqlSqlBaseWalker.java:1296)[optimized]
at org/hibernate/hql/antlr/HqlSqlBaseWalker.inRhs(HqlSqlBaseWalker.java:4200)[optimized]
at org/hibernate/hql/antlr/HqlSqlBaseWalker.comparisonExpr(HqlSqlBaseWalker.java:3842)
at org/hibernate/hql/antlr/HqlSqlBaseWalker.logicalExpr(HqlSqlBaseWalker.java:1762)
at org/hibernate/hql/antlr/HqlSqlBaseWalker.whereClause(HqlSqlBaseWalker.java:776)
at org/hibernate/hql/antlr/HqlSqlBaseWalker.query(HqlSqlBaseWalker.java:577)
at org/hibernate/hql/antlr/HqlSqlBaseWalker.selectStatement(HqlSqlBaseWalker.java:281)
at org/hibernate/hql/antlr/HqlSqlBaseWalker.statement(HqlSqlBaseWalker.java:229)
at org/hibernate/hql/ast/QueryTranslatorImpl.analyze(QueryTranslatorImpl.java:228)
at org/hibernate/hql/ast/QueryTranslatorImpl.doCompile(QueryTranslatorImpl.java:160)
at org/hibernate/hql/ast/QueryTranslatorImpl.compile(QueryTranslatorImpl.java:111)
at org/hibernate/engine/query/HQLQueryPlan.<init>(HQLQueryPlan.java:77)[inlined]
at org/hibernate/engine/query/HQLQueryPlan.<init>(HQLQueryPlan.java:56)[inlined]
at org/hibernate/engine/query/QueryPlanCache.getHQLQueryPlan(QueryPlanCache.java:72)[inlined]
at org/hibernate/impl/AbstractSessionImpl.getHQLQueryPlan(AbstractSessionImpl.java:133)[inlined]
at org/hibernate/impl/SessionImpl.list(SessionImpl.java:1113)[optimized]
at org/hibernate/impl/QueryImpl.list(QueryImpl.java:79)[optimized]
at org/hibernate/ejb/QueryImpl.getResultList(QueryImpl.java:64)[optimized]
--------- Detailed Heap Statistics: ---------
24.9% 38357k 701402 +36620k org/hibernate/hql/ast/tree/ParameterNode
15.5% 23871k 254019 +2157k [C
10.7% 16456k 702162 +15686k org/hibernate/param/NamedParameterSpecification
7.4% 11323k 724679 +10447k java/lang/Integer
Before hanging, the active thread '17' had time to print:
Code:
unable to locate HQL query plan in cache; generating (select i from XXXi where i.id IN (:ids0_, :ids1... 899
unable to locate HQL query plan in cache; generating (select new XXX( m.positionId, sum(m.quantity) ) from YYY m where (:lowerDate is null or m.accountingDate > :lowerDate) and (:upperDate is null or m.accountingDate <= :upperDate) and m.zzzId in (:zzzIds0_, ... 65
unable to locate HQL query plan in cache; generating (select new XXX( m.positionId, sum(m.netAmountPosCcy) ) from YYY m where (:lowerDate is null or m.accountingDate > :lowerDate) and (:upperDate is null or m.accountingDate <= :upperDate) and m.zzzId in (:zzzIds0_, :zzzIds1_, ... 833
unable to locate HQL query plan in cache; generating (select i from XXX i where i.id IN (:ids0_, ... 85
In spite of numerous tests (working on multithreading, multiple queries in the same entity manager, playing with the 128 plans limit in the query plan cache, ...) I was unable to reproduce the problem.
The only lead we have is to limit our use of IN queries, or limit the number of elements we can put in the IN itself (ex: 20, instead of 1000 currently, which is the max for oracle statements).
Environment:
- Hibernate core: 3.2.2.ga
- Hibernate entity manager: 3.2.1.ga
- DB: Oracle 10g
- App Server: weblogic 9.2MP3
- VM: BEA JRockit(R) 150_12 build R27.4.0
Has somebody found himself in the same situation. If so, how did you manage to workaround this problem?
Thanks,
Vince