Bug 980981

Summary: Evaluating simple rules with temp. operators takes much longer comparing to 5.3.1-P03
Product: [Retired] JBoss BRMS Platform 6 Reporter: Petr Široký <psiroky>
Component: BREAssignee: Mario Fusco <mfusco>
Status: CLOSED CURRENTRELEASE QA Contact: Petr Široký <psiroky>
Severity: high Docs Contact:
Priority: unspecified    
Version: 6.0.0CC: mfusco, mproctor, rzhang
Target Milestone: ER2   
Target Release: 6.0.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2014-08-06 20:17:11 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
Simple Maven based reproducer
none
Reproducer including both Drools5 and Drools6 projects. none

Description Petr Široký 2013-07-03 18:02:29 UTC
Description of problem:
I have a set o simple rules with temporal operators. Rules contain only "when" section, the "then" section is empty. Inserting some amount of facts (events) and firing the rules takes much longer with beta4 (and current snapshot) comparing with beta3. See attached Maven based reproducer - the reproducer contains only after and before operators, but this slow down was also seen with other temporal operators. 

For example the execution time for the attached reproducer:
 - beta3: 20ms
 - beta4: 3000ms

This issues was first seen with beta4 so it could be related to the new phreak algorithm.

Version-Release number of selected component (if applicable):
6.0.0.Beta4 and current 6.0.0-SNAPSHOT

How reproducible:
Always

Steps to Reproduce:
1. Run the attached reproducer (mvn test)
2. Change the version in pom.xml to beta3 and run it again.
3. Compare the times printed to stdout.

Actual results:
The execution time for beta4 (and current snapshot) is much longer comparing to beta3.

Expected results:
The execution time is same or better comparing to beta3.

Comment 1 Petr Široký 2013-07-03 18:04:21 UTC
Created attachment 768370 [details]
Simple Maven based reproducer

Comment 2 Mark Proctor 2013-07-03 18:26:48 UTC
KSession was slower in beta4, because of segment initialization is heavy. Mario has "proto" classed that initialization now, so after the first ksession, they should be quick to create.

Comment 3 Mario Fusco 2013-07-04 08:17:58 UTC
The problem was not caused by phreak (that indeed is faster than rete), but by the fact that the default event processing mode has been mistakenly set to STREAM instead of CLOUD, so that test was running in STREAM mode on beta4.

I fixed this.

Comment 4 Petr Široký 2013-07-04 10:11:18 UTC
So, should be the difference between running in CLOUD and STREAM mode that high? 20ms vs 3000ms? This seems not right to me. I will test it with 5.3.x to see if the difference is also there.

Comment 5 Petr Široký 2013-07-04 10:37:08 UTC
I ran the test with 5.3.1-P03 and the difference between CLOUD and STREAM mode is negligible. So the main problem is that the difference between these two processing options in Drools 6 is very high.

I will also update the reproducer to include the code for running with 5.3.1.-P03.

Comment 6 Petr Široký 2013-07-04 10:41:56 UTC
Created attachment 768725 [details]
Reproducer including both Drools5 and Drools6 projects.

Added Maven reproducer that includes code for both Drools 5 and Drools 6.
To run with  CLOUD option, just use "mvn test", for running in STREAM mode use "mvn test -Ddrools.mode=stream".

Comment 7 Mario Fusco 2013-07-04 16:37:01 UTC
I profiled the provided test case in STREAM mode and found that the culprit of this huge difference were 2 trace logging statements not guarded by a 

if ( log.isTraceEnabled() ) { ... }

block. I conditioned those log statements in that way (together with some other I found doing a full text search) and now phreak is slightly faster than rete even in STREAM mode.

Comment 8 Mario Fusco 2013-07-04 16:41:56 UTC
By the way I also added the possibility to pass a varargs of KieBaseOptions to the KieHelper when building the KieBase so, for example, now you can do:

kieBase = kieHelper.build(PhreakOption.ENABLED, EventProcessingOption.STREAM);

Comment 9 Petr Široký 2013-07-05 09:24:44 UTC
Thanks for the quick fix Mario! Will retest asap. 

And btw thanks for adding the possibility to configure KieBase when using KieHelper, this is really useful.

Comment 10 Petr Široký 2013-07-08 10:56:00 UTC
Verified fixed on 6.0.0 master. I will close this bz once verified also in product build.

Comment 12 Petr Široký 2013-08-31 17:45:09 UTC
Verified fixed in ER2.