Object size impact on session insertion performance

classic Classic list List threaded Threaded
9 messages Options
Reply | Threaded
Open this post in threaded view
|

Object size impact on session insertion performance

mikerod
This post was updated on .
Does the size of objects inserted into the session as facts directly affect performance?

I have ran some very simple tests, with a kb with 1 rule that accumulated/collected over all facts in working memory of a type.

If I have a really simple/small class, say SimpleClass

It looks like:

```
rule "collecting"
        when
        $res : List() from
                        accumulate( $s : SimpleClass(),
                                init( List l = new ArrayList(); ),
                                action( l.add($s); ),
                                result( l ))
        then
        System.out.println("Done");
end
```

If I have a more complex class that will result in deeply nested objects, say ComplexClass
It looks like:

```
rule "collecting"
        when
        $res : List() from
                        accumulate( $s : ComplexClass(), // this is the only difference from above
                                init( List l = new ArrayList(); ),
                                action( l.add($s); ),
                                result( l ))
        then
        System.out.println("Done");
end

Now my Java test is just a simple one that puts a timer before and after insert like:

```

// initialize kb and session as usual

// make N number of objects to insert of type SimpleClass or ComplexClass; depending on test run
// store them in local variable cs

        final long start = System.nanoTime();
        for (final SimpleClass c : cs) { // This would be ComplexClass when comparing
            ksession.insert(c);
        }
        final double end = ((System.nanoTime() - start) / 1000000.0);


        final int firedRules = ksession.fireAllRules(); // not really needed here

```

What I notice from these tests, is that for something like N=5000 of SimpleClass inserted into the session runs quick, say something like 35 sec.

However, for the same N=5000 of ComplexClass inserted into the session, the time jumps to something like 148 sec.

I haven't done exhaustive performance testing around this, but I am seeing this in more complex scenarios as well.
 I know that heap space (maybe perm space) play a role in this, but I have monitored my JVM processes  during execution and there is no lack of available heap space and my machine has a lot of resources available still in both SimpleClass and ComplexClass scenarios.

I am trying to understand if the actual size of an object inserted into the session has an affect on its overall performance.
This may be a trivial question and I'm just overlooking something, but I'd appreciate any advice and feedback on this subject.  I have not successfully been able to find any resources on the internet where this has been explicitly asked to base any thought off of.  I also have read up some on Rete (and variations e.g. Drools), but I don't see how the size of the objects inserted as facts applies to the insert performance.

Thanks!



Reply | Threaded
Open this post in threaded view
|

Re: [rules-users] Object size affect on session insertion performance

Mark Proctor
Other than the impact on heap and gc the size of the object does not impact performance.

You mention you have “deeply nested objects”, but your code is not showing if drools has visibility to those or not. If it’s not doing any additional traversal, then there should be no extra cost.

Maybe try a profiler? You might find there is time being used up in your object hierarchy somewhere, maybe construction and initialization?


Mark
On 22 Feb 2014, at 04:47, mikerod <[hidden email]> wrote:

> Does the size of objects inserted into the session as facts directly affect
> performance?
>
> I have ran some very simple tests, with a kb with 1 rule that
> accumulated/collected over all facts in working memory of a type.
>
> If I have a really simple/small class, say SimpleClass
>
> It looks like:
>
> ```
> rule "collecting"
> when
> $res : List() from
> accumulate( $s : SimpleClass(),
> init( List l = new ArrayList(); ),
> action( l.add($s); ),
> result( l ))
> then
> System.out.println("Done");
> end
> ```
>
> If I have a more complex class that will result in deeply nested objects,
> say ComplexClass
> It looks like:
>
> ```
> rule "collecting"
> when
> $res : List() from
> accumulate( $s : ComplexClass(), // this is the only difference from
> above
> init( List l = new ArrayList(); ),
> action( l.add($s); ),
> result( l ))
> then
> System.out.println("Done");
> end
>
> Now my Java test is just a simple one that puts a timer before and after
> insert like:
>
> ```
>
> // initialize kb and session as usual
>
> // make N number of objects to insert of type SimpleClass or ComplexClass;
> depending on test run
> // store them in local variable cs
>
>        final long start = System.nanoTime();
>        for (final SimpleClass c : cs) { // This would be ComplexClass when
> comparing
>            ksession.insert(c);
>        }
>        final double end = ((System.nanoTime() - start) / 1000000.0);
>
>
>        final int firedRules = ksession.fireAllRules(); // not really needed
> here
>
> ```
>
> What I notice from these tests, is that for something like N=5000 of
> SimpleClass inserted into the session runs quick, say something like 35 sec.
>
> However, for the same N=5000 of ComplexClass inserted into the session, the
> time jumps to something like 148 sec.
>
> I haven't done exhaustive performance testing around this, but I am seeing
> this in more complex scenarios as well.
> I know that heap space (maybe perm space) play a role in this, but I have
> monitored my JVM processes  during execution and there is no lack of
> available heap space and my machine has a lot of resources available still
> in both SimpleClass and ComplexClass scenarios.
>
> I am trying to understand if the actual size of an object inserted into the
> session has an affect on its overall performance.
> This may be a trivial question and I'm just overlooking something, but I'd
> appreciate any advice and feedback on this subject.  I have not successfully
> been able to find any resources on the internet where this has been
> explicitly asked to base any thought off of.  I also have read up some on
> Rete (and variations e.g. Drools), but I don't see how the size of the
> objects inserted as facts applies to the insert performance.
>
> Thanks!
>
>
>
>
>
>
>
> --
> View this message in context: http://drools.46999.n3.nabble.com/Object-size-affect-on-session-insertion-performance-tp4028244.html
> Sent from the Drools: User forum mailing list archive at Nabble.com.
> _______________________________________________
> rules-users mailing list
> [hidden email]
> https://lists.jboss.org/mailman/listinfo/rules-users


_______________________________________________
rules-users mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/rules-users
Reply | Threaded
Open this post in threaded view
|

Re: [rules-users] Object size affect on session insertion performance

laune
In reply to this post by mikerod
The durations you quote are hard to believe unless you run a very old
computer ;-)

I can insert 5000 Objects (3 fields) into a session with this single
"collecting" rule
in 0.28 seconds, which is several orders of magnitude faster than your 35 sec.

Are there other rules around? Some that refer only to ComplexClass?

-W

On 22/02/2014, mikerod <[hidden email]> wrote:

> Does the size of objects inserted into the session as facts directly affect
> performance?
>
> I have ran some very simple tests, with a kb with 1 rule that
> accumulated/collected over all facts in working memory of a type.
>
> If I have a really simple/small class, say SimpleClass
>
> It looks like:
>
> ```
> rule "collecting"
> when
> $res : List() from
> accumulate( $s : SimpleClass(),
> init( List l = new ArrayList(); ),
> action( l.add($s); ),
> result( l ))
> then
> System.out.println("Done");
> end
> ```
>
> If I have a more complex class that will result in deeply nested objects,
> say ComplexClass
> It looks like:
>
> ```
> rule "collecting"
> when
> $res : List() from
> accumulate( $s : ComplexClass(), // this is the only difference from
> above
> init( List l = new ArrayList(); ),
> action( l.add($s); ),
> result( l ))
> then
> System.out.println("Done");
> end
>
> Now my Java test is just a simple one that puts a timer before and after
> insert like:
>
> ```
>
> // initialize kb and session as usual
>
> // make N number of objects to insert of type SimpleClass or ComplexClass;
> depending on test run
> // store them in local variable cs
>
>         final long start = System.nanoTime();
>         for (final SimpleClass c : cs) { // This would be ComplexClass when
> comparing
>             ksession.insert(c);
>         }
>         final double end = ((System.nanoTime() - start) / 1000000.0);
>
>
>         final int firedRules = ksession.fireAllRules(); // not really
> needed
> here
>
> ```
>
> What I notice from these tests, is that for something like N=5000 of
> SimpleClass inserted into the session runs quick, say something like 35
> sec.
>
> However, for the same N=5000 of ComplexClass inserted into the session, the
> time jumps to something like 148 sec.
>
> I haven't done exhaustive performance testing around this, but I am seeing
> this in more complex scenarios as well.
>  I know that heap space (maybe perm space) play a role in this, but I have
> monitored my JVM processes  during execution and there is no lack of
> available heap space and my machine has a lot of resources available still
> in both SimpleClass and ComplexClass scenarios.
>
> I am trying to understand if the actual size of an object inserted into the
> session has an affect on its overall performance.
> This may be a trivial question and I'm just overlooking something, but I'd
> appreciate any advice and feedback on this subject.  I have not
> successfully
> been able to find any resources on the internet where this has been
> explicitly asked to base any thought off of.  I also have read up some on
> Rete (and variations e.g. Drools), but I don't see how the size of the
> objects inserted as facts applies to the insert performance.
>
> Thanks!
>
>
>
>
>
>
>
> --
> View this message in context:
> http://drools.46999.n3.nabble.com/Object-size-affect-on-session-insertion-performance-tp4028244.html
> Sent from the Drools: User forum mailing list archive at Nabble.com.
> _______________________________________________
> rules-users mailing list
> [hidden email]
> https://lists.jboss.org/mailman/listinfo/rules-users
>
_______________________________________________
rules-users mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/rules-users
Reply | Threaded
Open this post in threaded view
|

Re: [rules-users] Object size affect on session insertion performance

mikerod
@laune

You are correct that I actually put an incorrect time up before.  Thanks for pointing that out and sorry for the confusion.
The behavioral difference I have found was actually much large between the 2 classes, SimpleClass and ComplexClass, than I originally
thought.

The SimpleClass accumulate is very quick, around ~300 ms.  The ComplexClass accumulate (with the exact same rule beyond the object type)
spikes to around ~140 *seconds*.  In both cases this is with either 5K objects of one type inserted.

@Mark

I am sure that it is not the object creation time.  I create all of the objects before the timers and they are not lazy in any initialization.
However, you were right that I needed to run some profiling on this to dig into the real issue.

To start off, the culprit for this issue is the accumulate.  A rule without it like:
```
rule "not collecting"
        when
        ComplexClass() ; swap for SimpleClass on another run
        then
        System.out.println("Done");
end

```
runs about the same, no matter if it has a SimpleClass or ComplexClass.

Also, I'd like to just clarify, a SimpleClass here is just a class with 2 Integer fields (for this example).
However, the ComplexClass has around 15 fields and about half of these are Collections (aggregate) types with more nested classes underneath.
This is the difference I mean between "simple" and "complex" in a class; if that wasn't clear before.

Furthermore, there is only a single rule with only this very simple, contrived LHS logic in my example.  Drools is not needing
to traverse any of the objects and no additional work is done.  This is purely just a single rule being evaluated during an insert.
This is Drools v5.5.0.Final in this specific example (sorry for not mentioning that before).

---

I have seen a few related posts on what I have found, the #hashCode of my ComplexClass is taking nearly all of the time.
Upon further investigation, I found that this is happening because every insert to the session is causing the `result` portion of the accumulate to "recalculate".  During this step, the AccumulateContext `result` RightTuple is having its FactHandle reset to the newly calculated result.
This calls the #hashCode of the Collection that is holding all of the current ComplexClass object instances; and Collection calls the #hashCode of each of these (in j.u.Collection impl's such as j.u.AbstractList and j.u.AbstractSet).

So, I have a Collection, that is increasingly growing with ComplexClass object instances, and each time it grows by one, the #hashCode of the entire Collection of ComplexClass objects is being calculated.

The ComplexClass #hashCode is an aggregate of a recursive walk along across all of the objects' #hashCode it reaches through its fields, just like many aggregate types.  I think I can see that this could be expensive if this is being calculated for nearly 5K objects as each of the final objects are inserted causing the `result` recalculation.

---

I do realize that one potential workaround would be to put a blocking constraint above the accumulate:
```
rule "collecting"
        when
        BlockingFactClass()
        $res : Collection() from
                        accumulate( $s : ComplexClass(),
                                init( Collection c = new ArrayList(); ),
                                action( c.add($s); ),
                                result( c ))
                               
        then
        System.out.println("Done");
end
```
where the BlockingFactClass is not inserted until *after* all of the ComplexClass objects.  This speeds up the performance significantly; the time is nearly the same as the SimpleClass run actually.

---

I found that this was an interesting discovery and I did not expect this behavior.  

So @Mark it does seem (to me) that a deeply nested ComplexClass can hurt performance on an AccumulateNode when the `result` can be repeatedly calculated; even when the `result` is not "doing" anything besides returning what has been accumulated/collected.  I understand this is probably just a "gotcha" that I have to deal with.  This behavior is also the same for the Drools `collect` functionality, which I think just uses accumulate in the impl anyways (perhaps I'm incorrect).  Also, I note that this isn't necessary a direct "Object size affecting session insertion performance", as I originally titled this thread.

I also think that the new Phreak-based impl for Drools in v6.x may not behave like this anymore, since it is more lazy and delays work more until firing rules (an assumption here; haven't tested that).

With that said, I'm open to anymore suggestions about how to avoid this issue in pre-Phreak Drools (v6.x)
 (I am not sure how long until I am able to make that jump in version.).  

Also, I'm open to be corrected if my findings are incorrect/incomplete. :)  

Thanks again for the feedback!  It is helpful.
Reply | Threaded
Open this post in threaded view
|

Re: [rules-users] Object size affect on session insertion performance

Mark Proctor
"I have seen a few related posts on what I have found, the #hashCode of my
ComplexClass is taking nearly all of the time.
Upon further investigation, I found that this is happening because every
insert to the session is causing the `result` portion of the accumulate to
"recalculate”.  “

 There isn’t much we can do about your has code performance time. But if you upgrade to 6.0, the batch oriented propagation will reduce how often this is done, and hopefully minimise the difference. You won’t then need a blocking fact.

Mark
On 23 Feb 2014, at 03:38, mikerod <[hidden email]> wrote:

> @laune
>
> You are correct that I actually put an incorrect time up before.  Thanks for
> pointing that out and sorry for the confusion.
> The behavioral difference I have found was actually much large between the 2
> classes, SimpleClass and ComplexClass, than I originally
> thought.
>
> The SimpleClass accumulate is very quick, around ~300 ms.  The ComplexClass
> accumulate (with the exact same rule beyond the object type)
> spikes to around ~140 *seconds*.  In both cases this is with either 5K
> objects of one type inserted.
>
> @Mark
>
> I am sure that it is not the object creation time.  I create all of the
> objects before the timers and they are not lazy in any initialization.
> However, you were right that I needed to run some profiling on this to dig
> into the real issue.
>
> To start off, the culprit for this issue is the accumulate.  A rule without
> it like:
> ```
> rule "not collecting"
> when
> ComplexClass() ; swap for SimpleClass on another run
> then
> System.out.println("Done");
> end
>
> ```
> runs about the same, no matter if it has a SimpleClass or ComplexClass.
>
> Also, I'd like to just clarify, a SimpleClass here is just a class with 2
> Integer fields (for this example).
> However, the ComplexClass has around 15 fields and about half of these are
> Collections (aggregate) types with more nested classes underneath.
> This is the difference I mean between "simple" and "complex" in a class; if
> that wasn't clear before.
>
> Furthermore, there is only a single rule with only this very simple,
> contrived LHS logic in my example.  Drools is not needing
> to traverse any of the objects and no additional work is done.  This is
> purely just a single rule being evaluated during an insert.
> This is Drools v5.5.0.Final in this specific example (sorry for not
> mentioning that before).
>
> ---
>
> I have seen a few related posts on what I have found, the #hashCode of my
> ComplexClass is taking nearly all of the time.
> Upon further investigation, I found that this is happening because every
> insert to the session is causing the `result` portion of the accumulate to
> "recalculate".  During this step, the AccumulateContext `result` RightTuple
> is having its FactHandle reset to the newly calculated result.
> This calls the #hashCode of the Collection that is holding all of the
> current ComplexClass object instances; and Collection calls the #hashCode of
> each of these (in j.u.Collection impl's such as j.u.AbstractList and
> j.u.AbstractSet).
>
> So, I have a Collection, that is increasingly growing with ComplexClass
> object instances, and each time it grows by one, the #hashCode of the entire
> Collection of ComplexClass objects is being calculated.
>
> The ComplexClass #hashCode is an aggregate of a recursive walk along across
> all of the objects' #hashCode it reaches through its fields, just like many
> aggregate types.  I think I can see that this could be expensive if this is
> being calculated for nearly 5K objects as each of the final objects are
> inserted causing the `result` recalculation.
>
> ---
>
> I do realize that one potential workaround would be to put a blocking
> constraint above the accumulate:
> ```
> rule "collecting"
> when
> BlockingFactClass()
> $res : Collection() from
> accumulate( $s : ComplexClass(),
> init( Collection c = new ArrayList(); ),
> action( c.add($s); ),
> result( c ))
>
> then
> System.out.println("Done");
> end
> ```
> where the BlockingFactClass is not inserted until *after* all of the
> ComplexClass objects.  This speeds up the performance significantly; the
> time is nearly the same as the SimpleClass run actually.
>
> ---
>
> I found that this was an interesting discovery and I did not expect this
> behavior.  
>
> So @Mark it does seem (to me) that a deeply nested ComplexClass can hurt
> performance on an AccumulateNode when the `result` can be repeatedly
> calculated; even when the `result` is not "doing" anything besides returning
> what has been accumulated/collected.  I understand this is probably just a
> "gotcha" that I have to deal with.  This behavior is also the same for the
> Drools `collect` functionality, which I think just uses accumulate in the
> impl anyways (perhaps I'm incorrect).  Also, I note that this isn't
> necessary a direct "Object size affecting session insertion performance", as
> I originally titled this thread.
>
> I also think that the new Phreak-based impl for Drools in v6.x may not
> behave like this anymore, since it is more lazy and delays work more until
> firing rules (an assumption here; haven't tested that).
>
> With that said, I'm open to anymore suggestions about how to avoid this
> issue in pre-Phreak Drools (v6.x)
> (I am not sure how long until I am able to make that jump in version.).  
>
> Also, I'm open to be corrected if my findings are incorrect/incomplete. :)  
>
> Thanks again for the feedback!  It is helpful.
>
>
>
> --
> View this message in context: http://drools.46999.n3.nabble.com/Object-size-impact-on-session-insertion-performance-tp4028244p4028251.html
> Sent from the Drools: User forum mailing list archive at Nabble.com.
> _______________________________________________
> rules-users mailing list
> [hidden email]
> https://lists.jboss.org/mailman/listinfo/rules-users


_______________________________________________
rules-users mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/rules-users
Reply | Threaded
Open this post in threaded view
|

Re: [rules-users] Object size affect on session insertion performance

Mark Proctor
Please do report back to the list if 6.0 alleviates this problem, without needing a blocking fact.

Mark
On 23 Feb 2014, at 13:30, Mark Proctor <[hidden email]> wrote:

> "I have seen a few related posts on what I have found, the #hashCode of my
> ComplexClass is taking nearly all of the time.
> Upon further investigation, I found that this is happening because every
> insert to the session is causing the `result` portion of the accumulate to
> "recalculate”.  “
>
> There isn’t much we can do about your has code performance time. But if you upgrade to 6.0, the batch oriented propagation will reduce how often this is done, and hopefully minimise the difference. You won’t then need a blocking fact.
>
> Mark
> On 23 Feb 2014, at 03:38, mikerod <[hidden email]> wrote:
>
>> @laune
>>
>> You are correct that I actually put an incorrect time up before.  Thanks for
>> pointing that out and sorry for the confusion.
>> The behavioral difference I have found was actually much large between the 2
>> classes, SimpleClass and ComplexClass, than I originally
>> thought.
>>
>> The SimpleClass accumulate is very quick, around ~300 ms.  The ComplexClass
>> accumulate (with the exact same rule beyond the object type)
>> spikes to around ~140 *seconds*.  In both cases this is with either 5K
>> objects of one type inserted.
>>
>> @Mark
>>
>> I am sure that it is not the object creation time.  I create all of the
>> objects before the timers and they are not lazy in any initialization.
>> However, you were right that I needed to run some profiling on this to dig
>> into the real issue.
>>
>> To start off, the culprit for this issue is the accumulate.  A rule without
>> it like:
>> ```
>> rule "not collecting"
>> when
>> ComplexClass() ; swap for SimpleClass on another run
>> then
>> System.out.println("Done");
>> end
>>
>> ```
>> runs about the same, no matter if it has a SimpleClass or ComplexClass.
>>
>> Also, I'd like to just clarify, a SimpleClass here is just a class with 2
>> Integer fields (for this example).
>> However, the ComplexClass has around 15 fields and about half of these are
>> Collections (aggregate) types with more nested classes underneath.
>> This is the difference I mean between "simple" and "complex" in a class; if
>> that wasn't clear before.
>>
>> Furthermore, there is only a single rule with only this very simple,
>> contrived LHS logic in my example.  Drools is not needing
>> to traverse any of the objects and no additional work is done.  This is
>> purely just a single rule being evaluated during an insert.
>> This is Drools v5.5.0.Final in this specific example (sorry for not
>> mentioning that before).
>>
>> ---
>>
>> I have seen a few related posts on what I have found, the #hashCode of my
>> ComplexClass is taking nearly all of the time.
>> Upon further investigation, I found that this is happening because every
>> insert to the session is causing the `result` portion of the accumulate to
>> "recalculate".  During this step, the AccumulateContext `result` RightTuple
>> is having its FactHandle reset to the newly calculated result.
>> This calls the #hashCode of the Collection that is holding all of the
>> current ComplexClass object instances; and Collection calls the #hashCode of
>> each of these (in j.u.Collection impl's such as j.u.AbstractList and
>> j.u.AbstractSet).
>>
>> So, I have a Collection, that is increasingly growing with ComplexClass
>> object instances, and each time it grows by one, the #hashCode of the entire
>> Collection of ComplexClass objects is being calculated.
>>
>> The ComplexClass #hashCode is an aggregate of a recursive walk along across
>> all of the objects' #hashCode it reaches through its fields, just like many
>> aggregate types.  I think I can see that this could be expensive if this is
>> being calculated for nearly 5K objects as each of the final objects are
>> inserted causing the `result` recalculation.
>>
>> ---
>>
>> I do realize that one potential workaround would be to put a blocking
>> constraint above the accumulate:
>> ```
>> rule "collecting"
>> when
>> BlockingFactClass()
>> $res : Collection() from
>> accumulate( $s : ComplexClass(),
>> init( Collection c = new ArrayList(); ),
>> action( c.add($s); ),
>> result( c ))
>>
>> then
>> System.out.println("Done");
>> end
>> ```
>> where the BlockingFactClass is not inserted until *after* all of the
>> ComplexClass objects.  This speeds up the performance significantly; the
>> time is nearly the same as the SimpleClass run actually.
>>
>> ---
>>
>> I found that this was an interesting discovery and I did not expect this
>> behavior.  
>>
>> So @Mark it does seem (to me) that a deeply nested ComplexClass can hurt
>> performance on an AccumulateNode when the `result` can be repeatedly
>> calculated; even when the `result` is not "doing" anything besides returning
>> what has been accumulated/collected.  I understand this is probably just a
>> "gotcha" that I have to deal with.  This behavior is also the same for the
>> Drools `collect` functionality, which I think just uses accumulate in the
>> impl anyways (perhaps I'm incorrect).  Also, I note that this isn't
>> necessary a direct "Object size affecting session insertion performance", as
>> I originally titled this thread.
>>
>> I also think that the new Phreak-based impl for Drools in v6.x may not
>> behave like this anymore, since it is more lazy and delays work more until
>> firing rules (an assumption here; haven't tested that).
>>
>> With that said, I'm open to anymore suggestions about how to avoid this
>> issue in pre-Phreak Drools (v6.x)
>> (I am not sure how long until I am able to make that jump in version.).  
>>
>> Also, I'm open to be corrected if my findings are incorrect/incomplete. :)  
>>
>> Thanks again for the feedback!  It is helpful.
>>
>>
>>
>> --
>> View this message in context: http://drools.46999.n3.nabble.com/Object-size-impact-on-session-insertion-performance-tp4028244p4028251.html
>> Sent from the Drools: User forum mailing list archive at Nabble.com.
>> _______________________________________________
>> rules-users mailing list
>> [hidden email]
>> https://lists.jboss.org/mailman/listinfo/rules-users
>


_______________________________________________
rules-users mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/rules-users
Reply | Threaded
Open this post in threaded view
|

Re: [rules-users] Object size affect on session insertion performance

laune
Using OPs rule:

5.5.0
5000 facts, hashCode computed 12507500 times

6.0.0
5000 facts, hashCode computed 10000 times

After 5000 insertions and before fireAllRules, there were 5000
computations of hashCode. After the Engine is started, another 5000
computations occur.
This might bear investigation, although O(n) ist much better than O(n^2).

-W


On 23/02/2014, Mark Proctor <[hidden email]> wrote:

> Please do report back to the list if 6.0 alleviates this problem, without
> needing a blocking fact.
>
> Mark
> On 23 Feb 2014, at 13:30, Mark Proctor <[hidden email]> wrote:
>
>> "I have seen a few related posts on what I have found, the #hashCode of
>> my
>> ComplexClass is taking nearly all of the time.
>> Upon further investigation, I found that this is happening because every
>> insert to the session is causing the `result` portion of the accumulate
>> to
>> "recalculate".  "
>>
>> There isn't much we can do about your has code performance time. But if
>> you upgrade to 6.0, the batch oriented propagation will reduce how often
>> this is done, and hopefully minimise the difference. You won't then need a
>> blocking fact.
>>
>> Mark
>> On 23 Feb 2014, at 03:38, mikerod <[hidden email]> wrote:
>>
>>> @laune
>>>
>>> You are correct that I actually put an incorrect time up before.  Thanks
>>> for
>>> pointing that out and sorry for the confusion.
>>> The behavioral difference I have found was actually much large between
>>> the 2
>>> classes, SimpleClass and ComplexClass, than I originally
>>> thought.
>>>
>>> The SimpleClass accumulate is very quick, around ~300 ms.  The
>>> ComplexClass
>>> accumulate (with the exact same rule beyond the object type)
>>> spikes to around ~140 *seconds*.  In both cases this is with either 5K
>>> objects of one type inserted.
>>>
>>> @Mark
>>>
>>> I am sure that it is not the object creation time.  I create all of the
>>> objects before the timers and they are not lazy in any initialization.
>>> However, you were right that I needed to run some profiling on this to
>>> dig
>>> into the real issue.
>>>
>>> To start off, the culprit for this issue is the accumulate.  A rule
>>> without
>>> it like:
>>> ```
>>> rule "not collecting"
>>> when
>>> ComplexClass() ; swap for SimpleClass on another run
>>> then
>>> System.out.println("Done");
>>> end
>>>
>>> ```
>>> runs about the same, no matter if it has a SimpleClass or ComplexClass.
>>>
>>> Also, I'd like to just clarify, a SimpleClass here is just a class with
>>> 2
>>> Integer fields (for this example).
>>> However, the ComplexClass has around 15 fields and about half of these
>>> are
>>> Collections (aggregate) types with more nested classes underneath.
>>> This is the difference I mean between "simple" and "complex" in a class;
>>> if
>>> that wasn't clear before.
>>>
>>> Furthermore, there is only a single rule with only this very simple,
>>> contrived LHS logic in my example.  Drools is not needing
>>> to traverse any of the objects and no additional work is done.  This is
>>> purely just a single rule being evaluated during an insert.
>>> This is Drools v5.5.0.Final in this specific example (sorry for not
>>> mentioning that before).
>>>
>>> ---
>>>
>>> I have seen a few related posts on what I have found, the #hashCode of
>>> my
>>> ComplexClass is taking nearly all of the time.
>>> Upon further investigation, I found that this is happening because every
>>> insert to the session is causing the `result` portion of the accumulate
>>> to
>>> "recalculate".  During this step, the AccumulateContext `result`
>>> RightTuple
>>> is having its FactHandle reset to the newly calculated result.
>>> This calls the #hashCode of the Collection that is holding all of the
>>> current ComplexClass object instances; and Collection calls the #hashCode
>>> of
>>> each of these (in j.u.Collection impl's such as j.u.AbstractList and
>>> j.u.AbstractSet).
>>>
>>> So, I have a Collection, that is increasingly growing with ComplexClass
>>> object instances, and each time it grows by one, the #hashCode of the
>>> entire
>>> Collection of ComplexClass objects is being calculated.
>>>
>>> The ComplexClass #hashCode is an aggregate of a recursive walk along
>>> across
>>> all of the objects' #hashCode it reaches through its fields, just like
>>> many
>>> aggregate types.  I think I can see that this could be expensive if this
>>> is
>>> being calculated for nearly 5K objects as each of the final objects are
>>> inserted causing the `result` recalculation.
>>>
>>> ---
>>>
>>> I do realize that one potential workaround would be to put a blocking
>>> constraint above the accumulate:
>>> ```
>>> rule "collecting"
>>> when
>>> BlockingFactClass()
>>> $res : Collection() from
>>> accumulate( $s : ComplexClass(),
>>> init( Collection c = new ArrayList(); ),
>>> action( c.add($s); ),
>>> result( c ))
>>>
>>> then
>>> System.out.println("Done");
>>> end
>>> ```
>>> where the BlockingFactClass is not inserted until *after* all of the
>>> ComplexClass objects.  This speeds up the performance significantly; the
>>> time is nearly the same as the SimpleClass run actually.
>>>
>>> ---
>>>
>>> I found that this was an interesting discovery and I did not expect this
>>> behavior.
>>>
>>> So @Mark it does seem (to me) that a deeply nested ComplexClass can hurt
>>> performance on an AccumulateNode when the `result` can be repeatedly
>>> calculated; even when the `result` is not "doing" anything besides
>>> returning
>>> what has been accumulated/collected.  I understand this is probably just
>>> a
>>> "gotcha" that I have to deal with.  This behavior is also the same for
>>> the
>>> Drools `collect` functionality, which I think just uses accumulate in
>>> the
>>> impl anyways (perhaps I'm incorrect).  Also, I note that this isn't
>>> necessary a direct "Object size affecting session insertion performance",
>>> as
>>> I originally titled this thread.
>>>
>>> I also think that the new Phreak-based impl for Drools in v6.x may not
>>> behave like this anymore, since it is more lazy and delays work more
>>> until
>>> firing rules (an assumption here; haven't tested that).
>>>
>>> With that said, I'm open to anymore suggestions about how to avoid this
>>> issue in pre-Phreak Drools (v6.x)
>>> (I am not sure how long until I am able to make that jump in version.).
>>>
>>>
>>> Also, I'm open to be corrected if my findings are incorrect/incomplete.
>>> :)
>>>
>>> Thanks again for the feedback!  It is helpful.
>>>
>>>
>>>
>>> --
>>> View this message in context:
>>> http://drools.46999.n3.nabble.com/Object-size-impact-on-session-insertion-performance-tp4028244p4028251.html
>>> Sent from the Drools: User forum mailing list archive at Nabble.com.
>>> _______________________________________________
>>> rules-users mailing list
>>> [hidden email]
>>> https://lists.jboss.org/mailman/listinfo/rules-users
>>
>
>
> _______________________________________________
> rules-users mailing list
> [hidden email]
> https://lists.jboss.org/mailman/listinfo/rules-users
>
_______________________________________________
rules-users mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/rules-users
Reply | Threaded
Open this post in threaded view
|

Re: [rules-users] Object size affect on session insertion performance

Mark Proctor
We need to check where the 4999 are coming from. It makes sense that there are 5000 hashCode calls on object insertion, but unless i’m missing something there should be just one hashCode call for the accumulate node.

Line 692 should be called just once, per left input propagation for the accumulate per fireAllRules call:
https://github.com/droolsjbpm/drools/blob/master/drools-core/src/main/java/org/drools/core/phreak/PhreakAccumulateNode.java#L692

If line 692 is called just once, a profiler will highlight where else hashCode is being called. We can then investigate if it’s necessary, or if it can be avoided.

Mark

On 23 Feb 2014, at 15:03, Wolfgang Laun <[hidden email]> wrote:

> Using OPs rule:
>
> 5.5.0
> 5000 facts, hashCode computed 12507500 times
>
> 6.0.0
> 5000 facts, hashCode computed 10000 times
>
> After 5000 insertions and before fireAllRules, there were 5000
> computations of hashCode. After the Engine is started, another 5000
> computations occur.
> This might bear investigation, although O(n) ist much better than O(n^2).
>
> -W
>
>
> On 23/02/2014, Mark Proctor <[hidden email]> wrote:
>> Please do report back to the list if 6.0 alleviates this problem, without
>> needing a blocking fact.
>>
>> Mark
>> On 23 Feb 2014, at 13:30, Mark Proctor <[hidden email]> wrote:
>>
>>> "I have seen a few related posts on what I have found, the #hashCode of
>>> my
>>> ComplexClass is taking nearly all of the time.
>>> Upon further investigation, I found that this is happening because every
>>> insert to the session is causing the `result` portion of the accumulate
>>> to
>>> "recalculate".  "
>>>
>>> There isn't much we can do about your has code performance time. But if
>>> you upgrade to 6.0, the batch oriented propagation will reduce how often
>>> this is done, and hopefully minimise the difference. You won't then need a
>>> blocking fact.
>>>
>>> Mark
>>> On 23 Feb 2014, at 03:38, mikerod <[hidden email]> wrote:
>>>
>>>> @laune
>>>>
>>>> You are correct that I actually put an incorrect time up before.  Thanks
>>>> for
>>>> pointing that out and sorry for the confusion.
>>>> The behavioral difference I have found was actually much large between
>>>> the 2
>>>> classes, SimpleClass and ComplexClass, than I originally
>>>> thought.
>>>>
>>>> The SimpleClass accumulate is very quick, around ~300 ms.  The
>>>> ComplexClass
>>>> accumulate (with the exact same rule beyond the object type)
>>>> spikes to around ~140 *seconds*.  In both cases this is with either 5K
>>>> objects of one type inserted.
>>>>
>>>> @Mark
>>>>
>>>> I am sure that it is not the object creation time.  I create all of the
>>>> objects before the timers and they are not lazy in any initialization.
>>>> However, you were right that I needed to run some profiling on this to
>>>> dig
>>>> into the real issue.
>>>>
>>>> To start off, the culprit for this issue is the accumulate.  A rule
>>>> without
>>>> it like:
>>>> ```
>>>> rule "not collecting"
>>>> when
>>>> ComplexClass() ; swap for SimpleClass on another run
>>>> then
>>>> System.out.println("Done");
>>>> end
>>>>
>>>> ```
>>>> runs about the same, no matter if it has a SimpleClass or ComplexClass.
>>>>
>>>> Also, I'd like to just clarify, a SimpleClass here is just a class with
>>>> 2
>>>> Integer fields (for this example).
>>>> However, the ComplexClass has around 15 fields and about half of these
>>>> are
>>>> Collections (aggregate) types with more nested classes underneath.
>>>> This is the difference I mean between "simple" and "complex" in a class;
>>>> if
>>>> that wasn't clear before.
>>>>
>>>> Furthermore, there is only a single rule with only this very simple,
>>>> contrived LHS logic in my example.  Drools is not needing
>>>> to traverse any of the objects and no additional work is done.  This is
>>>> purely just a single rule being evaluated during an insert.
>>>> This is Drools v5.5.0.Final in this specific example (sorry for not
>>>> mentioning that before).
>>>>
>>>> ---
>>>>
>>>> I have seen a few related posts on what I have found, the #hashCode of
>>>> my
>>>> ComplexClass is taking nearly all of the time.
>>>> Upon further investigation, I found that this is happening because every
>>>> insert to the session is causing the `result` portion of the accumulate
>>>> to
>>>> "recalculate".  During this step, the AccumulateContext `result`
>>>> RightTuple
>>>> is having its FactHandle reset to the newly calculated result.
>>>> This calls the #hashCode of the Collection that is holding all of the
>>>> current ComplexClass object instances; and Collection calls the #hashCode
>>>> of
>>>> each of these (in j.u.Collection impl's such as j.u.AbstractList and
>>>> j.u.AbstractSet).
>>>>
>>>> So, I have a Collection, that is increasingly growing with ComplexClass
>>>> object instances, and each time it grows by one, the #hashCode of the
>>>> entire
>>>> Collection of ComplexClass objects is being calculated.
>>>>
>>>> The ComplexClass #hashCode is an aggregate of a recursive walk along
>>>> across
>>>> all of the objects' #hashCode it reaches through its fields, just like
>>>> many
>>>> aggregate types.  I think I can see that this could be expensive if this
>>>> is
>>>> being calculated for nearly 5K objects as each of the final objects are
>>>> inserted causing the `result` recalculation.
>>>>
>>>> ---
>>>>
>>>> I do realize that one potential workaround would be to put a blocking
>>>> constraint above the accumulate:
>>>> ```
>>>> rule "collecting"
>>>> when
>>>> BlockingFactClass()
>>>> $res : Collection() from
>>>> accumulate( $s : ComplexClass(),
>>>> init( Collection c = new ArrayList(); ),
>>>> action( c.add($s); ),
>>>> result( c ))
>>>>
>>>> then
>>>> System.out.println("Done");
>>>> end
>>>> ```
>>>> where the BlockingFactClass is not inserted until *after* all of the
>>>> ComplexClass objects.  This speeds up the performance significantly; the
>>>> time is nearly the same as the SimpleClass run actually.
>>>>
>>>> ---
>>>>
>>>> I found that this was an interesting discovery and I did not expect this
>>>> behavior.
>>>>
>>>> So @Mark it does seem (to me) that a deeply nested ComplexClass can hurt
>>>> performance on an AccumulateNode when the `result` can be repeatedly
>>>> calculated; even when the `result` is not "doing" anything besides
>>>> returning
>>>> what has been accumulated/collected.  I understand this is probably just
>>>> a
>>>> "gotcha" that I have to deal with.  This behavior is also the same for
>>>> the
>>>> Drools `collect` functionality, which I think just uses accumulate in
>>>> the
>>>> impl anyways (perhaps I'm incorrect).  Also, I note that this isn't
>>>> necessary a direct "Object size affecting session insertion performance",
>>>> as
>>>> I originally titled this thread.
>>>>
>>>> I also think that the new Phreak-based impl for Drools in v6.x may not
>>>> behave like this anymore, since it is more lazy and delays work more
>>>> until
>>>> firing rules (an assumption here; haven't tested that).
>>>>
>>>> With that said, I'm open to anymore suggestions about how to avoid this
>>>> issue in pre-Phreak Drools (v6.x)
>>>> (I am not sure how long until I am able to make that jump in version.).
>>>>
>>>>
>>>> Also, I'm open to be corrected if my findings are incorrect/incomplete.
>>>> :)
>>>>
>>>> Thanks again for the feedback!  It is helpful.
>>>>
>>>>
>>>>
>>>> --
>>>> View this message in context:
>>>> http://drools.46999.n3.nabble.com/Object-size-impact-on-session-insertion-performance-tp4028244p4028251.html
>>>> Sent from the Drools: User forum mailing list archive at Nabble.com.
>>>> _______________________________________________
>>>> rules-users mailing list
>>>> [hidden email]
>>>> https://lists.jboss.org/mailman/listinfo/rules-users
>>>
>>
>>
>> _______________________________________________
>> rules-users mailing list
>> [hidden email]
>> https://lists.jboss.org/mailman/listinfo/rules-users
>>
> _______________________________________________
> rules-users mailing list
> [hidden email]
> https://lists.jboss.org/mailman/listinfo/rules-users


_______________________________________________
rules-users mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/rules-users
Reply | Threaded
Open this post in threaded view
|

Re: [rules-users] Object size affect on session insertion performance

laune
@Mark: Note that I've been counting the FactClass::hashCode calls
only, not hashCode calls of all Objects. So you're hunting 5000 calls
but that extra one
won't spoil your day ;-)

-W

On 23/02/2014, Mark Proctor <[hidden email]> wrote:

> We need to check where the 4999 are coming from. It makes sense that there
> are 5000 hashCode calls on object insertion, but unless i'm missing
> something there should be just one hashCode call for the accumulate node.
>
> Line 692 should be called just once, per left input propagation for the
> accumulate per fireAllRules call:
> https://github.com/droolsjbpm/drools/blob/master/drools-core/src/main/java/org/drools/core/phreak/PhreakAccumulateNode.java#L692
>
> If line 692 is called just once, a profiler will highlight where else
> hashCode is being called. We can then investigate if it's necessary, or if
> it can be avoided.
>
> Mark
>
> On 23 Feb 2014, at 15:03, Wolfgang Laun <[hidden email]> wrote:
>
>> Using OPs rule:
>>
>> 5.5.0
>> 5000 facts, hashCode computed 12507500 times
>>
>> 6.0.0
>> 5000 facts, hashCode computed 10000 times
>>
>> After 5000 insertions and before fireAllRules, there were 5000
>> computations of hashCode. After the Engine is started, another 5000
>> computations occur.
>> This might bear investigation, although O(n) ist much better than O(n^2).
>>
>> -W
>>
>>
>> On 23/02/2014, Mark Proctor <[hidden email]> wrote:
>>> Please do report back to the list if 6.0 alleviates this problem,
>>> without
>>> needing a blocking fact.
>>>
>>> Mark
>>> On 23 Feb 2014, at 13:30, Mark Proctor <[hidden email]> wrote:
>>>
>>>> "I have seen a few related posts on what I have found, the #hashCode of
>>>> my
>>>> ComplexClass is taking nearly all of the time.
>>>> Upon further investigation, I found that this is happening because
>>>> every
>>>> insert to the session is causing the `result` portion of the accumulate
>>>> to
>>>> "recalculate".  "
>>>>
>>>> There isn't much we can do about your has code performance time. But if
>>>> you upgrade to 6.0, the batch oriented propagation will reduce how
>>>> often
>>>> this is done, and hopefully minimise the difference. You won't then need
>>>> a
>>>> blocking fact.
>>>>
>>>> Mark
>>>> On 23 Feb 2014, at 03:38, mikerod <[hidden email]> wrote:
>>>>
>>>>> @laune
>>>>>
>>>>> You are correct that I actually put an incorrect time up before.
>>>>> Thanks
>>>>> for
>>>>> pointing that out and sorry for the confusion.
>>>>> The behavioral difference I have found was actually much large between
>>>>> the 2
>>>>> classes, SimpleClass and ComplexClass, than I originally
>>>>> thought.
>>>>>
>>>>> The SimpleClass accumulate is very quick, around ~300 ms.  The
>>>>> ComplexClass
>>>>> accumulate (with the exact same rule beyond the object type)
>>>>> spikes to around ~140 *seconds*.  In both cases this is with either 5K
>>>>> objects of one type inserted.
>>>>>
>>>>> @Mark
>>>>>
>>>>> I am sure that it is not the object creation time.  I create all of
>>>>> the
>>>>> objects before the timers and they are not lazy in any initialization.
>>>>> However, you were right that I needed to run some profiling on this to
>>>>> dig
>>>>> into the real issue.
>>>>>
>>>>> To start off, the culprit for this issue is the accumulate.  A rule
>>>>> without
>>>>> it like:
>>>>> ```
>>>>> rule "not collecting"
>>>>> when
>>>>> ComplexClass() ; swap for SimpleClass on another run
>>>>> then
>>>>> System.out.println("Done");
>>>>> end
>>>>>
>>>>> ```
>>>>> runs about the same, no matter if it has a SimpleClass or
>>>>> ComplexClass.
>>>>>
>>>>> Also, I'd like to just clarify, a SimpleClass here is just a class
>>>>> with
>>>>> 2
>>>>> Integer fields (for this example).
>>>>> However, the ComplexClass has around 15 fields and about half of these
>>>>> are
>>>>> Collections (aggregate) types with more nested classes underneath.
>>>>> This is the difference I mean between "simple" and "complex" in a
>>>>> class;
>>>>> if
>>>>> that wasn't clear before.
>>>>>
>>>>> Furthermore, there is only a single rule with only this very simple,
>>>>> contrived LHS logic in my example.  Drools is not needing
>>>>> to traverse any of the objects and no additional work is done.  This
>>>>> is
>>>>> purely just a single rule being evaluated during an insert.
>>>>> This is Drools v5.5.0.Final in this specific example (sorry for not
>>>>> mentioning that before).
>>>>>
>>>>> ---
>>>>>
>>>>> I have seen a few related posts on what I have found, the #hashCode of
>>>>> my
>>>>> ComplexClass is taking nearly all of the time.
>>>>> Upon further investigation, I found that this is happening because
>>>>> every
>>>>> insert to the session is causing the `result` portion of the
>>>>> accumulate
>>>>> to
>>>>> "recalculate".  During this step, the AccumulateContext `result`
>>>>> RightTuple
>>>>> is having its FactHandle reset to the newly calculated result.
>>>>> This calls the #hashCode of the Collection that is holding all of the
>>>>> current ComplexClass object instances; and Collection calls the
>>>>> #hashCode
>>>>> of
>>>>> each of these (in j.u.Collection impl's such as j.u.AbstractList and
>>>>> j.u.AbstractSet).
>>>>>
>>>>> So, I have a Collection, that is increasingly growing with
>>>>> ComplexClass
>>>>> object instances, and each time it grows by one, the #hashCode of the
>>>>> entire
>>>>> Collection of ComplexClass objects is being calculated.
>>>>>
>>>>> The ComplexClass #hashCode is an aggregate of a recursive walk along
>>>>> across
>>>>> all of the objects' #hashCode it reaches through its fields, just like
>>>>> many
>>>>> aggregate types.  I think I can see that this could be expensive if
>>>>> this
>>>>> is
>>>>> being calculated for nearly 5K objects as each of the final objects
>>>>> are
>>>>> inserted causing the `result` recalculation.
>>>>>
>>>>> ---
>>>>>
>>>>> I do realize that one potential workaround would be to put a blocking
>>>>> constraint above the accumulate:
>>>>> ```
>>>>> rule "collecting"
>>>>> when
>>>>> BlockingFactClass()
>>>>> $res : Collection() from
>>>>> accumulate( $s : ComplexClass(),
>>>>> init( Collection c = new ArrayList(); ),
>>>>> action( c.add($s); ),
>>>>> result( c ))
>>>>>
>>>>> then
>>>>> System.out.println("Done");
>>>>> end
>>>>> ```
>>>>> where the BlockingFactClass is not inserted until *after* all of the
>>>>> ComplexClass objects.  This speeds up the performance significantly;
>>>>> the
>>>>> time is nearly the same as the SimpleClass run actually.
>>>>>
>>>>> ---
>>>>>
>>>>> I found that this was an interesting discovery and I did not expect
>>>>> this
>>>>> behavior.
>>>>>
>>>>> So @Mark it does seem (to me) that a deeply nested ComplexClass can
>>>>> hurt
>>>>> performance on an AccumulateNode when the `result` can be repeatedly
>>>>> calculated; even when the `result` is not "doing" anything besides
>>>>> returning
>>>>> what has been accumulated/collected.  I understand this is probably
>>>>> just
>>>>> a
>>>>> "gotcha" that I have to deal with.  This behavior is also the same for
>>>>> the
>>>>> Drools `collect` functionality, which I think just uses accumulate in
>>>>> the
>>>>> impl anyways (perhaps I'm incorrect).  Also, I note that this isn't
>>>>> necessary a direct "Object size affecting session insertion
>>>>> performance",
>>>>> as
>>>>> I originally titled this thread.
>>>>>
>>>>> I also think that the new Phreak-based impl for Drools in v6.x may not
>>>>> behave like this anymore, since it is more lazy and delays work more
>>>>> until
>>>>> firing rules (an assumption here; haven't tested that).
>>>>>
>>>>> With that said, I'm open to anymore suggestions about how to avoid
>>>>> this
>>>>> issue in pre-Phreak Drools (v6.x)
>>>>> (I am not sure how long until I am able to make that jump in
>>>>> version.).
>>>>>
>>>>>
>>>>> Also, I'm open to be corrected if my findings are
>>>>> incorrect/incomplete.
>>>>> :)
>>>>>
>>>>> Thanks again for the feedback!  It is helpful.
>>>>>
>>>>>
>>>>>
>>>>> --
>>>>> View this message in context:
>>>>> http://drools.46999.n3.nabble.com/Object-size-impact-on-session-insertion-performance-tp4028244p4028251.html
>>>>> Sent from the Drools: User forum mailing list archive at Nabble.com.
>>>>> _______________________________________________
>>>>> rules-users mailing list
>>>>> [hidden email]
>>>>> https://lists.jboss.org/mailman/listinfo/rules-users
>>>>
>>>
>>>
>>> _______________________________________________
>>> rules-users mailing list
>>> [hidden email]
>>> https://lists.jboss.org/mailman/listinfo/rules-users
>>>
>> _______________________________________________
>> rules-users mailing list
>> [hidden email]
>> https://lists.jboss.org/mailman/listinfo/rules-users
>
>
> _______________________________________________
> rules-users mailing list
> [hidden email]
> https://lists.jboss.org/mailman/listinfo/rules-users
>
_______________________________________________
rules-users mailing list
[hidden email]
https://lists.jboss.org/mailman/listinfo/rules-users