Re: [rules-users] Confusing behavior for StatefulKnowledgeSession.fireAllRules() with negated conditions.

Hello again, Recently while continuing to work on a complex event processing project I have encountered strange, but interesting, situations where the fireAllRules() method of a StatefulKnowledgeSession appears to return before actually emptying the activations on the agenda. I was under the impression that this method only returns after all activations, including subsequent activations, have been completed and removed from the agenda. If I'm incorrect then feel free to disregard the rest of this message. [Drools v 5.0.1, JUnit 4.0, Spring 2.5.6] The behavior I have noticed begins when working with a rule such as "Find Missing Input Events" (in file test.drl): ------------------------------------------------------------------------ package org.drools.test import org.drools.test.* declare Event @role( event ) @timestamp( beginning ) @duration( length ) @expires( 1h ) end declare Fault @role( event ) @timestamp( beginning ) @duration( length ) @expires( 1h ) end query "getFaults" $fault: Fault() from entry-point "faults" end rule "Find Missing Input Events" when $a: Event() from entry-point "input" $b: Event( this after $a) from entry-point "input" not (Event( (this after $a || this metby $a), (this before $b || this meets $b)) from entry-point "input") not (Fault(this metby $a, this meets $b) from entry-point "faults") then entryPoints["faults"].insert(new Fault($a, $b)); end rule "Print Faults" when $f: Fault() from entry-point "faults" then System.out.println($f); end ------------------------------------------------------------------------ The purpose of this rule is to detect when one or more events are missing in an event sequence. The events in question are supposed to continue from one to the next without any time in-between. If this rule does discover a gap/absence between two events a Fault is created for further processing. (*Note that the Event and Fault classes that I used only contain two fields, beginning and length, to be used as the time-stamp and duration respectively.) I noticed the unexpected behavior shortly after creating this unit test: ------------------------------------------------------------------------ public class FireAllRulesTest { KnowledgeBase knowledgeBase; StatefulKnowledgeSession session; /** * @throws java.lang.Exception */ @Before public void setUp() throws Exception { KnowledgeBuilder builder = KnowledgeBuilderFactory.newKnowledgeBuilder(); builder.add(ResourceFactory.newFileResource("target/test-classes/test.drl"), ResourceType.DRL); if(builder.hasErrors()){ throw new RuntimeException(builder.getErrors().toString()); } KnowledgeBaseConfiguration configuration = KnowledgeBaseFactory.newKnowledgeBaseConfiguration(); configuration.setOption(EventProcessingOption.STREAM); knowledgeBase = KnowledgeBaseFactory.newKnowledgeBase(configuration); knowledgeBase.addKnowledgePackages(builder.getKnowledgePackages()); session = knowledgeBase.newStatefulKnowledgeSession(); WorkingMemoryConsoleLogger logger = new WorkingMemoryConsoleLogger(session); } @Test public void testAbsence(){ System.out.println("Running..."); //Record the rules that have fired. ActivationTrackingEventListener listener = new ActivationTrackingEventListener(); session.addEventListener(listener); //Start at 0, go to 100. Event first = new Event(0,100); //Start at 1000, go to 1100. Absence of 900. Event second = new Event(1000, 100); //Start at 1100, go to 1200. No absence. Event third = new Event(1100, 100); //Start at 1200, go to 1300. No absence. Event fourth = new Event(1200, 100); //Start at 2000, go to 2100. Absence of 700. Event fifth = new Event(2000, 100); WorkingMemoryEntryPoint ingest = session.getWorkingMemoryEntryPoint("input"); ingest.insert(first); ingest.insert(second); ingest.insert(third); ingest.insert(fourth); ingest.insert(fifth); System.out.println("All events have been inserted."); session.fireAllRules(); System.out.println("Rules have finished firing."); //Expect that "Find Missing Input Events" has fired and that there are two faults as a result. assertTrue(listener.hasRuleFired("Find Missing Input Events")); assertEquals(2,faultCount()); System.out.println("Test completed."); } public int faultCount(){ QueryResults results = session.getQueryResults("getFaults"); return results.size(); } } ------------------------------------------------------------------------ The typical result of this test is a failure about 90% of the time. Strangely, the other 10% of the time this exact same test is run it will pass, without any modifications. Equally interesting is the output of the WorkingMemoryLogger: ------------------------------------------------------------------------ Running... OBJECT ASSERTED value:org.drools.test.Event@1b994de factId: 1 BEFORE ACTIVATION FIRED rule:Find Missing Input Events activationId:Find Missing Input Events [2, 1, 0] declarations: $b=org.drools.test.Event@2803d5(2); $a=org.drools.test.Event@1b994de(1) ACTIVATION CREATED rule:Find Missing Input Events activationId:Find Missing Input Events [2, 1, 0] declarations: $b=org.drools.test.Event@2803d5(2); $a=org.drools.test.Event@1b994de(1) OBJECT ASSERTED value:org.drools.test.Event@2803d5 factId: 2 OBJECT ASSERTED value:org.drools.test.Event@1b32627 factId: 3 OBJECT ASSERTED value:org.drools.test.Event@ad157f factId: 4 ACTIVATION CREATED rule:Find Missing Input Events activationId:Find Missing Input Events [5, 4, 0] declarations: $b=org.drools.test.Event@1bfa3d3(5); $a=org.drools.test.Event@ad157f(4) OBJECT ASSERTED value:org.drools.test.Event@1bfa3d3 factId: 5 All events have been inserted. ***Rules have finished firing. ACTIVATION CREATED rule:Print Faults activationId:Print Faults [6, 0] declarations: $f=org.drools.test.Fault@159780d(6) OBJECT ASSERTED value:org.drools.test.Fault@159780d factId: 6 AFTER ACTIVATION FIRED rule:Find Missing Input Events activationId:Find Missing Input Events [2, 1, 0] declarations: $b=org.drools.test.Event@2803d5(2); $a=org.drools.test.Event@1b994de(1) BEFORE ACTIVATION FIRED rule:Print Faults activationId:Print Faults [6, 0] declarations: $f=org.drools.test.Fault@159780d(6) org.drools.test.Fault@159780d AFTER ACTIVATION FIRED rule:Print Faults activationId:Print Faults [6, 0] declarations: $f=org.drools.test.Fault@159780d(6) BEFORE ACTIVATION FIRED rule:Find Missing Input Events activationId:Find Missing Input Events [5, 4, 0] declarations: $b=org.drools.test.Event@1bfa3d3(5); $a=org.drools.test.Event@ad157f(4) ACTIVATION CREATED rule:Print Faults activationId:Print Faults [7, 0] declarations: $f=org.drools.test.Fault@c26b16(7) OBJECT ASSERTED value:org.drools.test.Fault@c26b16 factId: 7 AFTER ACTIVATION FIRED rule:Find Missing Input Events activationId:Find Missing Input Events [5, 4, 0] declarations: $b=org.drools.test.Event@1bfa3d3(5); $a=org.drools.test.Event@ad157f(4) BEFORE ACTIVATION FIRED rule:Print Faults activationId:Print Faults [7, 0] declarations: $f=org.drools.test.Fault@c26b16(7) org.drools.test.Fault@c26b16 AFTER ACTIVATION FIRED rule:Print Faults activationId:Print Faults [7, 0] declarations: $f=org.drools.test.Fault@c26b16(7) ------------------------------------------------------------------------ It seems that the rule is indeed firing correctly, but that it is doing so only after returning from fireAllRules method. I have marked line that follows fireAllRules() with *** above. So the rule fires, but the test fails because the firing takes place after the junit assertions are checked. But that's not all, it gets more interesting. Looking back at the rule file, when you comment out the last condition: not (Fault(this metby $a, this meets $b) from entry-point "faults") The problem with the unit test disappears. After much thought I'm still not sure why this is, but the last condition is critical to avoid creating redundant Faults (Because a lot of the Events are redundant as well. It just comes with the problem being solved). The problem also disappears if you put a Thread.sleep(1000) after firing the rules, which is why I suspect a timing issue between the rules firing and the unit test assertions being evaluated. This could explain why the test sometimes works, and sometimes doesn't. I'm hopeful that someone will understand why this is happening, and point how how to prevent it. Thank you in advance. Bill _______________________________________________ rules-users mailing list rules-users(a)lists.jboss.org https://lists.jboss.org/mailman/listinfo/rules-users