Hi,
I have been trying to measure Drools' 5.5.0 performance for quite some time. I see that Drools' perform inconsistently in terms of CPU time.
Please see the below code
(modification of DroolsTest example):
/*Code start*/
public class DroolsTest {
public static final void main(String[] args) {
try {
// load up the knowledge base
KnowledgeBase kbase = readKnowledgeBase();
// go !
for (int i = 0; i < 20; i++) {
Message message = new Message();
message.setMessage("Hello World");
message.setStatus(Message.HELLO);
long startTime = System.nanoTime();
StatefulKnowledgeSession ksession = kbase.newStatefulKnowledgeSession();
FactHandle handle = ksession.insert(message);
ksession.fireAllRules();
ksession.retract(handle);
System.out.println("Time taken is: " + (System.nanoTime()-startTime)/1000);
ksession.dispose();
}
} catch (Throwable t) {
t.printStackTrace();
}
}
private static KnowledgeBase readKnowledgeBase() throws Exception {
KnowledgeBuilder kbuilder = KnowledgeBuilderFactory.newKnowledgeBuilder();
kbuilder.add(ResourceFactory.newClassPathResource("Sample.drl"), ResourceType.DRL);
KnowledgeBuilderErrors errors = kbuilder.getErrors();
if (errors.size() > 0) {
for (KnowledgeBuilderError error: errors) {
System.err.println(error);
}
throw new IllegalArgumentException("Could not parse knowledge.");
}
KnowledgeBase kbase = KnowledgeBaseFactory.newKnowledgeBase();
kbase.addKnowledgePackages(kbuilder.getKnowledgePackages());
return kbase;
}
public static class Message {
public static final int HELLO = 0;
public static final int GOODBYE = 1;
private String message;
private int status;
public String getMessage() {
return this.message;
}
public void setMessage(String message) {
this.message = message;
}
public int getStatus() {
return this.status;
}
public void setStatus(int status) {
this.status = status;
}
}
}
/** Code end**/
I have just added timing code to the DroolsTest.java program (provided by JBoss) and I am using Sample.drl file (provided by JBoss). The rules get executed correctly but the timings that I see are:
Iteration 1: 103753 (we can ignore this as the classes get loaded during the first iteration)
Iteration 2: 861
Iteration 3: 744
Iteration 4: 1350
Iteration 5: 718
Iteration 6: 651
Iteration 7: 661
Iteration 8: 668
Iteration 9: 648
Iteration 10:
3564
Iteration 11: 911
Iteration 12: 689
Iteration 13: 682
Iteration 14: 796
Iteration 15: 4236
Iteration 16: 774
Iteration 17: 772
Iteration 18: 722
Iteration 19: 713
Iteration 20: 697
I profiled it with Yourkit Profiler and the increase in time does not correspond to garbage collection. I also timed individual calls and found out that:
- ksession.insert: takes consistent time
- ksession.fireAllRules: inconsistent
- kbase.newStatefulKnowledgeSession: inconsistent
I see same inconsistency in performance when I integrate Drools with original project (which I can't share here). I also found that this has nothing to do with compiler
optimizations.
Why is there inconsistent performance? Is there anything that I am missing?
Thank you.