[jboss-jira] [JBoss JIRA] Updated: (JBRULES-3116) Performance Regression due to mvel ParserContext now set, resulting in CompositeClassLoader loads

[Fabian Lange (JIRA)]

     [ https://issues.jboss.org/browse/JBRULES-3116?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Fabian Lange updated JBRULES-3116:
----------------------------------

    Description: 
I observed this issue already with 5.1, but now had time to verify it with 5.2.
Initial compilation time has exploded with those versions.

I have with the same test cases with 5.2 this:
{{org.drools.util.CompositeClassLoader$CachingLoader.load}} taking a total of 42 seconds
With 5.0 (where this Caching was not yet implemented)
I had a total time of less than 5 seconds spend in the ClassLoading.

The reason for this took me a while to find, but now I do have it:
{{org.mvel2.compiler.AbstractParser.createPropertyToken}}

is invoking {{hasImports()}} and {{getImport()}} on the ParseContext if not null:
see:
https://github.com/mikebrock/mvel/blob/master/src/main/java/org/mvel2/compiler/AbstractParser.java#L1292

Those in turn are invoking {{org.mvel2.ParserConfiguration.checkForDynamicImport}}
which invokes {{org.drools.util.CompositeClassLoader.loadClass}}

This is invoked on my table for expressions like this: "{{age >= 16}}"
So the {{org.drools.util.CompositeClassLoader$CachingLoader.load}}
will look for a class called "age" and a class called "16". Because the class not exists null/false are returned from the callchain.
However neither the {{CachingLoader}}, nor the Map in {{AbstractParser}} will cache the negative result. Causing this to happen for each row in my decisiontable.

And in 5.0 the whole part of the callgraph is not there.
I figured out, that in 5.0 versions, the {{AbstractParser}} never had a parse context in createPropertyToken

This might be because of the inconsistent usage of
{code}
protected static ThreadLocal<ParserContext> parserContext;
protected ParserContext pCtx;
{code}

So where does us leave this?
A possible easy solution would be to add the "negative" lookups to the CachingLoader.
However I would like to have doublechecked if the change in Abstract Parser was intentional and is now working correctly. Thus invoking the checkDynamicImports a lot is correct. Is it really the case that the parser needs to check for each literal this dynamic import thing? it obviously didnt do before.




  was:
I observed this issue already with 5.1, but now had time to verify it with 5.2.
Initial compilation time has exploded with those versions.

I have with the same test cases with 5.2 this:
org.drools.util.CompositeClassLoader$CachingLoader.load taking a total of 42 seconds
With 5.0 (where this Caching was not yet implemented)
I had a total time of less than 5 seconds spend in the ClassLoading.

The reason for this took me a while to find, but now I do have it:

org.mvel2.compiler.AbstractParser.createPropertyToken

is invoking hasImports() and getImport() on the ParseContext if not null.
Those in turn are invoking org.mvel2.ParserConfiguration.checkForDynamicImport
which invokes org.drools.util.CompositeClassLoader.loadClass

This is invoked on my table for expressions like this: "age >= 16"
So the org.drools.util.CompositeClassLoader$CachingLoader.load
will look for a class called "age" and a class called "16". Because the class not exists null/false are returned from the callchain.
However neither the CachingLoader, nor the Map in AbstractParser will cache the negative result. Causing this to happen for each row in my decisiontable.

And in 5.0 the whole part of the callgraph is not there.
I figured out, that in 5.0 versions, the AbstractParser never had a parse context in createPropertyToken

This might be because of the inconsistent usage of
    protected static ThreadLocal<ParserContext> parserContext;
    protected ParserContext pCtx;


So where does us leave this?
A possible easy solution would be to add the "negative" lookups to the CachingLoader.
However I would like to have doublechecked if the change in Abstract Parser was intentional and is now working correctly. Thus invoking the checkDynamicImports a lot is correct. Is it really the case that the parser needs to check for each literal this dynamic import thing? it obviously didnt do before.






> Performance Regression due to mvel ParserContext now set, resulting in CompositeClassLoader loads
> -------------------------------------------------------------------------------------------------
>
>                 Key: JBRULES-3116
>                 URL: https://issues.jboss.org/browse/JBRULES-3116
>             Project: Drools
>          Issue Type: Bug
>      Security Level: Public(Everyone can see) 
>          Components: drools-compiler
>    Affects Versions: 5.2.0.Final
>            Reporter: Fabian Lange
>            Assignee: Mark Proctor
>         Attachments: abstractParser-bug1.png
>
>
> I observed this issue already with 5.1, but now had time to verify it with 5.2.
> Initial compilation time has exploded with those versions.
> I have with the same test cases with 5.2 this:
> {{org.drools.util.CompositeClassLoader$CachingLoader.load}} taking a total of 42 seconds
> With 5.0 (where this Caching was not yet implemented)
> I had a total time of less than 5 seconds spend in the ClassLoading.
> The reason for this took me a while to find, but now I do have it:
> {{org.mvel2.compiler.AbstractParser.createPropertyToken}}
> is invoking {{hasImports()}} and {{getImport()}} on the ParseContext if not null:
> see:
> https://github.com/mikebrock/mvel/blob/master/src/main/java/org/mvel2/compiler/AbstractParser.java#L1292
> Those in turn are invoking {{org.mvel2.ParserConfiguration.checkForDynamicImport}}
> which invokes {{org.drools.util.CompositeClassLoader.loadClass}}
> This is invoked on my table for expressions like this: "{{age >= 16}}"
> So the {{org.drools.util.CompositeClassLoader$CachingLoader.load}}
> will look for a class called "age" and a class called "16". Because the class not exists null/false are returned from the callchain.
> However neither the {{CachingLoader}}, nor the Map in {{AbstractParser}} will cache the negative result. Causing this to happen for each row in my decisiontable.
> And in 5.0 the whole part of the callgraph is not there.
> I figured out, that in 5.0 versions, the {{AbstractParser}} never had a parse context in createPropertyToken
> This might be because of the inconsistent usage of
> {code}
> protected static ThreadLocal<ParserContext> parserContext;
> protected ParserContext pCtx;
> {code}
> So where does us leave this?
> A possible easy solution would be to add the "negative" lookups to the CachingLoader.
> However I would like to have doublechecked if the change in Abstract Parser was intentional and is now working correctly. Thus invoking the checkDynamicImports a lot is correct. Is it really the case that the parser needs to check for each literal this dynamic import thing? it obviously didnt do before.

--
This message is automatically generated by JIRA.
For more information on JIRA, see: http://www.atlassian.com/software/jira