Re: [rules-dev] memory issue (memory leak?) on trunk (probably due true modify changes)

On 14/03/2010 01:50, Greg Barton wrote: > Isn't that what Geoffrey just said? :) > > Anyone tried different GC approaches with this? Running with the concurrent collector might be a useful stopgap until the object creation is tamped down. > The new algorithm should now have less objects created than before, so this indicates something is wrong somewhere. Mark > --- On Sat, 3/13/10, Michael Neale&lt;michael.neale(a)gmail.com&gt; wrote: > > >> From: Michael Neale&lt;michael.neale(a)gmail.com&gt; >> Subject: Re: [rules-dev] memory issue (memory leak?) on trunk (probably due true modify changes) >> To: "Rules Dev List&quot;&lt;rules-dev(a)lists.jboss.org&gt; >> Cc: &quot;rules-dev@lists.jboss.org&quot;&lt;rules-dev(a)lists.jboss.org&gt; >> Date: Saturday, March 13, 2010, 5:54 PM >> Interesting error. >> >> One explanation of it: http://stackoverflow.com/questions/1393486/what-means-the-error-message-j... >> >> Sent from my phone. >> >> On 13/03/2010, at 8:21 PM, Geoffrey De Smet&lt;ge0ffrey.spam(a)gmail.com&gt; >> >> wrote: >> >> >>> Hi guys, >>> >>> With great improvements usually come instability for a >>> >> while :) >> >>> Trunk has memory issue, probably a memory leak of a >>> >> small object. >> >>> I've run ExmaminationBenchmarkApp with the program arg >>> >> "short" 3 times >> >>> with the exact same configuration (it is a 100% >>> >> reproducible run): >> >>> 1) Before the true modify changes with 512m max >>> >> memory >> >>> Succeeds (100 steps but even 10000 steps work) with no >>> >> slow down. >> >>> 2) After true modify changes with 512m max memory >>> Fails after 27 steps, starts slowing down at 24 >>> >> steps. >> >>> 3) After true modify changes with 1024m max memory >>> Fails after 57 steps, starts slowing down at 54 >>> >> steps. >> >>> Both 2) and 3) fail with the exception: >>> Exception in thread "main" java.lang.OutOfMemoryError: >>> >> GC overhead >> >>> limit >>> exceeded >>> >>> So it's not a heap space error or a perm space error, >>> >> but a GC >> >>> overhead >>> limit instead. Literally this means it's doing more GC >>> >> then running, >> >>> but 99% of the time this means that the heap is so >>> >> full that the GC >> >>> has >>> little or no free space to work with. >>> This kind of memory leak happens when the iteration >>> >> make 101 objects >> >>> but >>> only removes 100 objects and the iteration is run a >>> >> lot (like 10000+ >> >>> times). >>> You don't get a heap space error, because before that >>> >> happens, >> >>> there is point where you have a garbaged collected >>> >> free memory for 10 >> >>> objects and a ungarbaged collected free memory for 100 >>> >> objects. At >> >>> that >>> point the GC is running over 98% of the time, which is >>> >> a VM treshold >> >>> and >>> the error is thrown, >>> even though 10 iterations later you would get a heap >>> >> space error. >> >>> Logs: >>> >>> 1) >>> TODO >>> >>> 2) >>> 2010-03-13 09:28:36,973 [main] INFO Step index >>> >> (21), time spend >> >>> (37245) >>> taking step (323 {D180|S9} @ 9 {D210} + 5 {C65} => >>> >> 52 {D210}) out of >> >>> 1402 accepted moves. >>> 2010-03-13 09:28:38,454 [main] INFO Step index >>> >> (22), time spend >> >>> (38727) >>> taking step (367 {D190|S40} @ 28 {D210} + 5 {C65} >>> >> => 19 {D210}) out of >> >>> 1366 accepted moves. >>> 2010-03-13 09:28:39,903 [main] INFO Step index >>> >> (23), time spend >> >>> (40176) >>> taking step (230 {D120|S15} @ 7 {D210} + 3 {C60} => >>> >> 12 {D210}) out of >> >>> 1366 accepted moves. >>> 2010-03-13 09:28:43,901 [main] INFO Step index >>> >> (24), time spend >> >>> (44174) >>> taking step (190 {D90|S6} @ 1 {D210} + 3 {C60} >>> >> <=> 205 {D120|S6} @ 8 >> >>> {D210} + 6 {C111}) out of 1392 accepted moves. >>> 2010-03-13 09:28:50,631 [main] INFO Step index >>> >> (25), time spend >> >>> (50904) >>> taking step (420 {D180|S6} @ 46 {D210} + 2 {C129} >>> >> => 25 {D210}) out of >> >>> 1396 accepted moves. >>> 2010-03-13 09:29:06,184 [main] INFO Step index >>> >> (26), time spend >> >>> (66457) >>> taking step (211 {D180|S53} @ 15 {D210} + 0 {C260} >>> >> => 23 {D210}) out >> >>> of >>> 1383 accepted moves. >>> 2010-03-13 09:29:46,589 [main] INFO Step index >>> >> (27), time spend >> >>> (106862) taking step (39 {D120|S15} @ 50 {D210} + 2 >>> >> {C129} => 43 >> >>> {D210}) >>> out of 1383 accepted moves. >>> Exception in thread "main" java.lang.OutOfMemoryError: >>> >> GC overhead >> >>> limit >>> exceeded >>> at >>> >> java.util.HashMap.addEntry(HashMap.java:753) >> >>> at >>> >> java.util.HashMap.put(HashMap.java:385) >> >>> at >>> >> java.util.HashMap.putAll(HashMap.java:524) >> >>> at >>> org.drools.rule.GroupElement$Type.getOuterDeclarations >>> >> >>> (GroupElement.java:406) >>> at >>> >> org.drools.rule.GroupElement.getOuterDeclarations >> >>> (GroupElement.java:109) >>> at >>> org.drools.base.DefaultKnowledgeHelper.getDeclaration >>> >> >>> (DefaultKnowledgeHelper.java:213) >>> at >>> >>> >> org.drools.planner.examples.examination.solver.Rule_periodSpread_0DefaultConsequenceInvoker.evaluate( >> >> >>> Rule_periodSpread_0DefaultConsequenceInvoker.java:21) >>> at >>> >> org.drools.common.DefaultAgenda.fireActivation >> >>> (DefaultAgenda.java:903) >>> at >>> >> org.drools.common.DefaultAgenda.fireNextItem >> >>> (DefaultAgenda.java:850) >>> at >>> >> org.drools.common.DefaultAgenda.fireAllRules >> >>> (DefaultAgenda.java:1061) >>> at >>> org.drools.common.AbstractWorkingMemory.fireAllRules >>> (AbstractWorkingMemory.java:741) >>> at >>> org.drools.common.AbstractWorkingMemory.fireAllRules >>> (AbstractWorkingMemory.java:707) >>> ... >>> >>> 3) >>> 2010-03-13 09:47:38,303 [main] INFO Step index >>> >> (55), time spend >> >>> (114213) taking step (186 {D90|S17} @ 24 {D210} + 5 >>> >> {C65}<=> 516 >> >>> {D180|S12} @ 15 {D210} + 0 {C260}) out of 1382 >>> >> accepted moves. >> >>> 2010-03-13 09:48:02,062 [main] INFO Step index >>> >> (56), time spend >> >>> (137972) taking step (498 {D120|S17} @ 28 {D210} + 0 >>> >> {C260} => 1 >> >>> {C100}) >>> out of 1389 accepted moves. >>> 2010-03-13 09:48:35,748 [main] INFO Step index >>> >> (57), time spend >> >>> (171658) taking step (15 {D135|S96} @ 16 {D210} + 1 >>> >> {C100}<=> 164 >> >>> {D180|S48} @ 3 {D210} + 0 {C260}) out of 1378 accepted >>> >> moves. >> >>> Exception in thread "main" java.lang.OutOfMemoryError: >>> >> GC overhead >> >>> limit >>> exceeded >>> at >>> >> java.lang.Integer.valueOf(Integer.java:625) >> >>> at >>> >>> >> org.drools.common.TruthMaintenanceSystem.removeLogicalDependencies >> >> >>> (TruthMaintenanceSystem.java:180) >>> at >>> >>> >> org.drools.common.AbstractWorkingMemory.removeLogicalDependencies >> >> >>> (AbstractWorkingMemory.java:1455) >>> at >>> org.drools.reteoo.RuleTerminalNode.retractLeftTuple >>> (RuleTerminalNode.java:266) >>> at >>> >>> >> org.drools.reteoo.SingleLeftTupleSinkAdapter.doPropagateRetractLeftTuple( >> >> >>> SingleLeftTupleSinkAdapter.java:176) >>> at >>> >>> >> org.drools.reteoo.SingleLeftTupleSinkAdapter.propagateRetractLeftTuple( >> >> >>> SingleLeftTupleSinkAdapter.java:57) >>> at >>> org.drools.reteoo.EvalConditionNode.modifyLeftTuple >>> (EvalConditionNode.java:250) >>> at >>> >>> >> org.drools.reteoo.SingleLeftTupleSinkAdapter.propagateModifyChildLeftTuple( >> >> >>> SingleLeftTupleSinkAdapter.java:198) >>> at >>> >> org.drools.reteoo.JoinNode.modifyLeftTuple(JoinNode.java:304) >> >>> at >>> >>> >> org.drools.reteoo.SingleLeftTupleSinkAdapter.propagateModifyChildLeftTuple( >> >> >>> SingleLeftTupleSinkAdapter.java:209) >>> at >>> >> org.drools.reteoo.JoinNode.modifyRightTuple(JoinNode.java:221) >> >>> at >>> >> org.drools.reteoo.BetaNode.modifyObject(BetaNode.java:317) >> >>> at >>> >>> >> org.drools.reteoo.CompositeObjectSinkAdapter.doPropagateModifyObject >> >> >>> (CompositeObjectSinkAdapter.java:444) >>> at >>> >>> >> org.drools.reteoo.CompositeObjectSinkAdapter.propagateModifyObject >> >> >>> (CompositeObjectSinkAdapter.java:412) >>> at >>> >> org.drools.reteoo.ObjectTypeNode.modifyObject >> >>> (ObjectTypeNode.java:262) >>> at >>> >> org.drools.reteoo.EntryPointNode.modifyObject >> >>> (EntryPointNode.java:174) >>> at >>> org.drools.common.AbstractWorkingMemory.update >>> (AbstractWorkingMemory.java:1392) >>> at >>> org.drools.common.AbstractWorkingMemory.update >>> (AbstractWorkingMemory.java:1288) >>> >>> >>> -- >>> With kind regards, >>> Geoffrey De Smet >>> >>> _______________________________________________ >>> rules-dev mailing list >>> rules-dev(a)lists.jboss.org >>> https://lists.jboss.org/mailman/listinfo/rules-dev >>> >> _______________________________________________ >> rules-dev mailing list >> rules-dev(a)lists.jboss.org >> https://lists.jboss.org/mailman/listinfo/rules-dev >> >> > > > _______________________________________________ > rules-dev mailing list > rules-dev(a)lists.jboss.org > https://lists.jboss.org/mailman/listinfo/rules-dev > > _______________________________________________ rules-dev mailing list rules-dev(a)lists.jboss.org https://lists.jboss.org/mailman/listinfo/rules-dev