<html><head><meta http-equiv="Content-Type" content="text/html charset=windows-1252"></head><body style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space;">For those that don’t know, the new algorithm supports a detailed trace mode. Create a logback.xml and set the level to trace.&nbsp;<div><div style="border: 1px inset; padding: 29px; position: static; z-index: auto;"><pre bgcolor="#ffffff" style="margin-top: 0px; margin-bottom: 0px; padding: 6px; background-color: rgb(255, 255, 255); font-family: Menlo; position: static; z-index: auto;"><font bgcolor="#efefef"><span style="background-color: rgb(239, 239, 239);">&lt;</span></font><font color="#000080"><font bgcolor="#efefef"><b><span style="background-color: rgb(239, 239, 239);">logger </span></b></font></font><font color="#0000ff"><font bgcolor="#efefef"><b><span style="background-color: rgb(239, 239, 239);">name=</span></b></font></font><font color="#008000"><font bgcolor="#efefef"><b><span style="background-color: rgb(239, 239, 239);">"org.drools" </span></b></font></font><font color="#0000ff"><font bgcolor="#efefef"><b><span style="background-color: rgb(239, 239, 239);">level=</span></b></font></font><font color="#008000"><font bgcolor="#efefef"><b><span style="background-color: rgb(239, 239, 239);">"trace"</span></b></font></font><font color="#000000"><font bgcolor="#efefef"><span style="background-color: rgb(239, 239, 239);">/&gt;</span></font></font></pre></div></div><div><br></div><div>You’ll then get outputs like the following, which shows you what rules fired and when, and with what amounts of data for each node. It also shows you when rules are linked and unlinked.<br><div><div><br></div><div><div>2014-02-25 05:00:16,023 [main] DEBUG Starting Engine in PHREAK mode</div><div>2014-02-25 05:00:16,084 [main] TRACE Adding Rule R1</div><div>2014-02-25 05:00:16,088 [main] TRACE Adding Rule R2</div><div>2014-02-25 05:00:16,134 [main] TRACE Insert [fact 0:1:1708041420:1708041420:1:DEFAULT:NON_TRAIT:org.drools.compiler.integrationtests.Misc2Test$Foo@65cea4cc]</div><div>2014-02-25 05:00:16,142 [main] TRACE LinkNode notify=false nmask=1 smask=1 spos=0 rules=</div><div>2014-02-25 05:00:16,142 [main] TRACE &nbsp; LinkSegment smask=2 rmask=2 name=R2</div><div>2014-02-25 05:00:16,146 [main] TRACE LinkNode notify=true nmask=1 smask=1 spos=0 rules=[RuleMem R1], [RuleMem R2]</div><div>2014-02-25 05:00:16,147 [main] TRACE Insert [fact 0:2:281271144:281271144:2:DEFAULT:NON_TRAIT:org.drools.compiler.integrationtests.Misc2Test$Foo2@10c3db68]</div><div>2014-02-25 05:00:16,148 [main] TRACE BetaNode insert=1 stagedInsertWasEmpty=true</div><div>2014-02-25 05:00:16,148 [main] TRACE LinkNode notify=true nmask=2 smask=3 spos=0 rules=[RuleMem R1], [RuleMem R2]</div><div>2014-02-25 05:00:16,148 [main] TRACE &nbsp; LinkSegment smask=1 rmask=1 name=R1</div><div>2014-02-25 05:00:16,149 [main] TRACE &nbsp; LinkSegment smask=1 rmask=3 name=R2</div><div>2014-02-25 05:00:16,149 [main] TRACE &nbsp; &nbsp; LinkRule name=R2</div><div>2014-02-25 05:00:16,161 [main] TRACE Queue RuleAgendaItem [Activation rule=R2, act#=0, salience=0, tuple=null]</div><div>2014-02-25 05:00:16,161 [main] TRACE Queue Added 1 [Activation rule=R2, act#=0, salience=0, tuple=null]</div><div>2014-02-25 05:00:16,161 [main] TRACE Added R2 to eager evaluation list.</div><div>2014-02-25 05:00:16,162 [main] TRACE Rule[name=R2] segments=2 TupleSets[insertSize=1, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,162 [main] TRACE &nbsp; &nbsp; &nbsp;1 [JoinNode(5) - [ClassObjectType class=org.drools.compiler.integrationtests.Misc2Test$Foo2]] TupleSets[insertSize=1, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,163 [main] TRACE &nbsp; &nbsp; &nbsp;Segment 0</div><div>2014-02-25 05:00:16,163 [main] TRACE &nbsp; &nbsp; &nbsp;1 [JoinNode(5) - [ClassObjectType class=org.drools.compiler.integrationtests.Misc2Test$Foo2]] TupleSets[insertSize=1, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,167 [main] TRACE &nbsp; &nbsp; &nbsp;rightTuples TupleSets[insertSize=1, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,168 [main] TRACE &nbsp; &nbsp; &nbsp;Segment 1</div><div>2014-02-25 05:00:16,168 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp;2 [NotNode(9) - [ClassObjectType class=org.drools.compiler.Person]] TupleSets[insertSize=1, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,169 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp;Segment 1</div><div>2014-02-25 05:00:16,169 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp;2 [NotNode(9) - [ClassObjectType class=org.drools.compiler.Person]] TupleSets[insertSize=1, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,169 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp;rightTuples TupleSets[insertSize=0, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,171 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp; &nbsp;3 [RuleTerminalNode(10): rule=R2] TupleSets[insertSize=1, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,171 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp; &nbsp;Segment 1</div><div>2014-02-25 05:00:16,171 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp; &nbsp;3 [RuleTerminalNode(10): rule=R2] TupleSets[insertSize=1, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,172 [main] TRACE Fire "R2"&nbsp;</div><div>[[ R2 active=false ] [ null</div><div>[fact 0:2:281271144:281271144:2:DEFAULT:NON_TRAIT:org.drools.compiler.integrationtests.Misc2Test$Foo2@10c3db68]</div><div>[fact 0:1:1708041420:1708041420:1:DEFAULT:NON_TRAIT:org.drools.compiler.integrationtests.Misc2Test$Foo@65cea4cc] ] ]</div><div>2014-02-25 05:00:16,177 [main] TRACE Update [fact 0:2:281271144:281271144:3:DEFAULT:NON_TRAIT:org.drools.compiler.integrationtests.Misc2Test$Foo2@10c3db68]</div><div>2014-02-25 05:00:16,178 [main] TRACE &nbsp; LinkSegment smask=1 rmask=1 name=R1</div><div>2014-02-25 05:00:16,178 [main] TRACE &nbsp; LinkSegment smask=1 rmask=3 name=R2</div><div>2014-02-25 05:00:16,178 [main] TRACE &nbsp; &nbsp; LinkRule name=R2</div><div>2014-02-25 05:00:16,178 [main] TRACE Added R2 to eager evaluation list.</div><div>2014-02-25 05:00:16,179 [main] TRACE Insert [fact 0:3:1226345699:-62068830:4:DEFAULT:LEGACY_TRAITABLE:[Person name='null age='0' likes='null']]</div><div>2014-02-25 05:00:16,179 [main] TRACE BetaNode insert=1 stagedInsertWasEmpty=true</div><div>2014-02-25 05:00:16,179 [main] TRACE LinkNode notify=true nmask=1 smask=1 spos=1 rules=[RuleMem R1]</div><div>2014-02-25 05:00:16,180 [main] TRACE &nbsp; LinkSegment smask=2 rmask=3 name=R1</div><div>2014-02-25 05:00:16,180 [main] TRACE &nbsp; &nbsp; LinkRule name=R1</div><div>2014-02-25 05:00:16,180 [main] TRACE Queue RuleAgendaItem [Activation rule=R1, act#=2, salience=0, tuple=null]</div><div>2014-02-25 05:00:16,180 [main] TRACE Queue Added 1 [Activation rule=R1, act#=2, salience=0, tuple=null]</div><div>2014-02-25 05:00:16,181 [main] TRACE LinkNode notify=true nmask=1 smask=1 spos=1 rules=[RuleMem R2]</div><div>2014-02-25 05:00:16,181 [main] TRACE &nbsp; LinkSegment smask=2 rmask=3 name=R2</div><div>2014-02-25 05:00:16,181 [main] TRACE &nbsp; &nbsp; LinkRule name=R2</div><div>2014-02-25 05:00:16,181 [main] TRACE Added R2 to eager evaluation list.</div><div>2014-02-25 05:00:16,181 [main] TRACE Rule[name=R2] segments=2 TupleSets[insertSize=0, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,182 [main] TRACE &nbsp; &nbsp; &nbsp;4 [JoinNode(5) - [ClassObjectType class=org.drools.compiler.integrationtests.Misc2Test$Foo2]] TupleSets[insertSize=0, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,182 [main] TRACE &nbsp; &nbsp; &nbsp;Segment 0</div><div>2014-02-25 05:00:16,182 [main] TRACE &nbsp; &nbsp; &nbsp;4 [JoinNode(5) - [ClassObjectType class=org.drools.compiler.integrationtests.Misc2Test$Foo2]] TupleSets[insertSize=0, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,183 [main] TRACE &nbsp; &nbsp; &nbsp;rightTuples TupleSets[insertSize=0, deleteSize=0, updateSize=1]</div><div>2014-02-25 05:00:16,183 [main] TRACE &nbsp; &nbsp; &nbsp;Segment 1</div><div>2014-02-25 05:00:16,183 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp;5 [NotNode(9) - [ClassObjectType class=org.drools.compiler.Person]] TupleSets[insertSize=0, deleteSize=0, updateSize=1]</div><div>2014-02-25 05:00:16,184 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp;Segment 1</div><div>2014-02-25 05:00:16,184 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp;5 [NotNode(9) - [ClassObjectType class=org.drools.compiler.Person]] TupleSets[insertSize=0, deleteSize=0, updateSize=1]</div><div>2014-02-25 05:00:16,184 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp;rightTuples TupleSets[insertSize=1, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,184 [main] TRACE UnlinkNode notify=true nmask=1 smask=0 spos=1 rules=[RuleMem R2]</div><div>2014-02-25 05:00:16,185 [main] TRACE &nbsp; UnlinkSegment smask=2 rmask=1 name=[RuleMem R2]</div><div>2014-02-25 05:00:16,185 [main] TRACE &nbsp; &nbsp; UnlinkRule name=R2</div><div>2014-02-25 05:00:16,185 [main] TRACE Added R2 to eager evaluation list.</div><div>2014-02-25 05:00:16,185 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp; &nbsp;6 [RuleTerminalNode(10): rule=R2] TupleSets[insertSize=0, deleteSize=1, updateSize=0]</div><div>2014-02-25 05:00:16,186 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp; &nbsp;Segment 1</div><div>2014-02-25 05:00:16,186 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp; &nbsp;6 [RuleTerminalNode(10): rule=R2] TupleSets[insertSize=0, deleteSize=1, updateSize=0]</div><div>2014-02-25 05:00:16,187 [main] TRACE Rule[name=R2] segments=2 TupleSets[insertSize=0, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,187 [main] TRACE &nbsp; &nbsp; &nbsp;7 [JoinNode(5) - [ClassObjectType class=org.drools.compiler.integrationtests.Misc2Test$Foo2]] TupleSets[insertSize=0, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,188 [main] TRACE &nbsp; &nbsp; &nbsp;Skip Segment 0</div><div>2014-02-25 05:00:16,188 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp;Segment 1</div><div>2014-02-25 05:00:16,188 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp;7 [NotNode(9) - [ClassObjectType class=org.drools.compiler.Person]] TupleSets[insertSize=0, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,188 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp;rightTuples TupleSets[insertSize=0, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,188 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp; &nbsp;8 [RuleTerminalNode(10): rule=R2] TupleSets[insertSize=0, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,189 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp; &nbsp;Segment 1</div><div>2014-02-25 05:00:16,189 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp; &nbsp;8 [RuleTerminalNode(10): rule=R2] TupleSets[insertSize=0, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,189 [main] TRACE Rule[name=R2] segments=2 TupleSets[insertSize=0, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,189 [main] TRACE &nbsp; &nbsp; &nbsp;9 [JoinNode(5) - [ClassObjectType class=org.drools.compiler.integrationtests.Misc2Test$Foo2]] TupleSets[insertSize=0, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,190 [main] TRACE &nbsp; &nbsp; &nbsp;Skip Segment 0</div><div>2014-02-25 05:00:16,190 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp;Segment 1</div><div>2014-02-25 05:00:16,190 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp;9 [NotNode(9) - [ClassObjectType class=org.drools.compiler.Person]] TupleSets[insertSize=0, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,191 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp;rightTuples TupleSets[insertSize=0, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,191 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp; &nbsp;10 [RuleTerminalNode(10): rule=R2] TupleSets[insertSize=0, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,191 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp; &nbsp;Segment 1</div><div>2014-02-25 05:00:16,191 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp; &nbsp;10 [RuleTerminalNode(10): rule=R2] TupleSets[insertSize=0, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,192 [main] TRACE Rule[name=R1] segments=2 TupleSets[insertSize=0, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,192 [main] TRACE &nbsp; &nbsp; &nbsp;11 [JoinNode(5) - [ClassObjectType class=org.drools.compiler.integrationtests.Misc2Test$Foo2]] TupleSets[insertSize=0, deleteSize=0, updateSize=0]</div><div>2014-02-25 05:00:16,192 [main] TRACE &nbsp; &nbsp; &nbsp;Skip Segment 0</div><div>2014-02-25 05:00:16,192 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp;Segment 1</div><div>2014-02-25 05:00:16,192 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp;11 [JoinNode(7) - [ClassObjectType class=org.drools.compiler.Person]] TupleSets[insertSize=0, deleteSize=0, updateSize=1]</div><div>2014-02-25 05:00:16,193 [main] TRACE &nbsp; &nbsp; &nbsp; &nbsp;rightTuples TupleSets[insertSize=1, deleteSize=0, updateSize=0]</div><div><br></div><div>java.lang.NullPointerException</div><div><span class="Apple-tab-span" style="white-space:pre">        </span>at org.drools.core.util.index.LeftTupleIndexHashTable.remove(LeftTupleIndexHashTable.java:386)</div><div><span class="Apple-tab-span" style="white-space:pre">        </span>at org.drools.core.phreak.RuleNetworkEvaluator.doUpdatesReorderLeftMemory(RuleNetworkEvaluator.java:799)</div></div></div></div></body></html>