[rules-users] Rule set execution performance and memory consumption issues

[Joe Ammann]

Hi Wolfgang

On 08/04/2013 03:10 PM, Wolfgang Laun wrote:
> A simple test shows that, with the rules as shown, you can insert 100k
> Assignments and an equal number of SourceAssignments (with ~300
> InstrumentList facts) in a matter of seconds, irrespective of the
> number of hits and  misses, either way. I suspect that there is some
> other fly in the ointment.
I suspect this too, but am unable to lay my fingers on it,
unfortunately. That's why I started to question my basic pattern. But
all my test trying to get to the core of the problem showed the same as
your quick tests - there is absolutely no fundamental problem handling a
couple of 100'000 objects.
>
> There is no "Instrument" pattern in any of the rules, which makes your
> post slightly inconsistent in itself.
Right - I was trying to explain the pattern which I suspected to be the
culprit, without posting a dozen Java classes and a couple of dozens of
rules. Always a difficult thing to do. The real rules have many more
patterns, after matching the basic objects, e.g.

rule "R1110: MatchExistingAssignment"
when
    sa : SourcingAssignment( )
    a : Assignment( instrumentId == sa.instrumentId, instrumentListId ==
sa.instrumentListId )
    i  : Instrument( id == instrumentId, foType == FOTYPE.Stock,
statusCd == INSTRUMENT_STATUS.Draft )
    not DQAttribute ( rootId == i.id, attributePath ==
Instrument._ATTR_statusCd )
    ....
 then

I think I have in the meantime found the main issue - it was one single
rule that caused the majority of the problem. It was written really
stupidly ... The time is now down to ~ 2 minutes. Still I see in the log

2013-08-05 00:36:56.224 [ain] DEBUG:                         Check:
start inserting objects into working memory {|||||| - |}
2013-08-05 00:36:56.225 [ain] DEBUG:                         Check: next
object type: SourcingInstrument, (12668 instances) {|||||| - |}
2013-08-05 00:36:56.701 [ain] DEBUG:                         Check: next
object type: SourcingInstrumentList, (38 instances) {|||||| - |}
2013-08-05 00:36:56.707 [ain] DEBUG:                         Check: next
object type: SourcingAssignment, (194693 instances) {|||||| - |}
2013-08-05 00:36:57.573 [ain] DEBUG:                         Check: next
object type: Instrument, (17876 instances) {|||||| - |}
2013-08-05 00:37:41.009 [ain] DEBUG:                         Check: next
object type: InstrumentList, (49 instances) {|||||| - |}
2013-08-05 00:37:41.359 [ain] DEBUG:                         Check:
finished inserting objects into working memory {|||||| - |}
2013-08-05 00:37:41.360 [ain] DEBUG:                         Check: fire
validate staging rules {|||||| - |}
2013-08-05 00:37:43.502 [ain] DEBUG:                         Check:
validate staging rules finished, 147674 executed {|||||| - |}
2013-08-05 00:37:43.502 [ain] DEBUG:                         Check:
start inserting objects into working memory {|||||| - |}
2013-08-05 00:37:43.502 [ain] DEBUG:                         Check: next
object type: Assignment, (120006 instances) {|||||| - |}
2013-08-05 00:37:50.114 [ain] DEBUG:                         Check:
finished inserting objects into working memory {|||||| - |}

And I'm wondering a bit why inserting 17876 Instruments takes 45
seconds, while inserting 194693 SourcingAssignments takes less than a
second.

I must admit that I have absolutely no clue how I would systematically
debug such a situation and try to find out which rules are causing the
"problem". I stumbled over this one stupid rule just by going through
them one by one. I'm trying to get some experience to cope with such
problems - since I'm not the only one writing the rules, I continue to
see such "unexplicable" slowdowns.

Sigh - I guess I still have A LOT to learn about Drools :-)

Thanks for your help Wolfgang - and BTW: your whitepaper about rule
patterns is a major reference for my learning.

-- 
CU, Joe