[
https://issues.apache.org/jira/browse/WW-5147?focusedWorklogId=680500&page=com.atlassian.jira.plugin.system.issuetabpanels:worklog-tabpanel#worklog-680500
]
ASF GitHub Bot logged work on WW-5147:
--------------------------------------
Author: ASF GitHub Bot
Created on: 11/Nov/21 22:31
Start Date: 11/Nov/21 22:31
Worklog Time Spent: 10m
Work Description: davoustp commented on pull request #504:
URL: https://github.com/apache/struts/pull/504#issuecomment-966671933
Very good question, indeed. ;-)
This is because this single expression can be evaluated through a chain, and
the way the method {{ognl.ASTChain.getValueBody(OgnlContext, Object)}} is built
can lead to method {{ognl.OgnlRuntime.getProperty(OgnlContext, Object,
Object)}} throwing a {{OgnlException("source is null for getProperty(null, \""
+ name + "\")")}} (line 2733).
Hence the expression is not cached, before this code change.
Here a stack trace of the such an occurence (Struts 2.5.20):
`Daemon Thread [http-nio-8080-exec-6] (Suspended (breakpoint at line 2733 in
OgnlRuntime))
owns: NioEndpoint$NioSocketWrapper (id=294)
OgnlRuntime.getProperty(OgnlContext, Object, Object) line: 2733
ASTProperty.getValueBody(OgnlContext, Object) line: 114
ASTProperty(SimpleNode).evaluateGetValueBody(OgnlContext, Object) line:
212
ASTProperty(SimpleNode).getValue(OgnlContext, Object) line: 258
ASTChain.getValueBody(OgnlContext, Object) line: 141
ASTChain(SimpleNode).evaluateGetValueBody(OgnlContext, Object) line: 212
ASTChain(SimpleNode).getValue(OgnlContext, Object) line: 258
Ognl.getValue(Object, Map, Object, Class) line: 470
Ognl.getValue(Object, Map, Object) line: 434
OgnlUtil$2.execute(Object) line: 401
OgnlUtil.compileAndExecute(String, Map<String,Object>, OgnlTask<T>)
line: 442
OgnlUtil.getValue(String, Map<String,Object>, Object) line: 399
OgnlValueStack.getValueUsingOgnl(String) line: 293
OgnlValueStack.tryFindValue(String) line: 276
OgnlValueStack.tryFindValueWhenExpressionIsNotNull(String) line: 258
OgnlValueStack.findValue(String, boolean) line: 238
OgnlValueStack.findValue(String) line: 300
StrutsRequestWrapper.getAttribute(String) line: 94
...`
And a few values of the {{name}} attribute of method
{{ognl.OgnlRuntime.getProperty(OgnlContext, Object, Object)}} creating this
scenario:
`actionMapping
opensymphony
apache
valueStack
actiontag
servlet
Application__
Request__`
And finally a stack trace for the {{actionMapping}} case:
`Daemon Thread [http-nio-8080-exec-6] (Suspended (breakpoint at line 2733 in
OgnlRuntime))
owns: NioEndpoint$NioSocketWrapper (id=294)
OgnlRuntime.getProperty(OgnlContext, Object, Object) line: 2733
ASTProperty.getValueBody(OgnlContext, Object) line: 114
ASTProperty(SimpleNode).evaluateGetValueBody(OgnlContext, Object) line:
212
ASTProperty(SimpleNode).getValue(OgnlContext, Object) line: 258
ASTChain.getValueBody(OgnlContext, Object) line: 141
ASTChain(SimpleNode).evaluateGetValueBody(OgnlContext, Object) line: 212
ASTChain(SimpleNode).getValue(OgnlContext, Object) line: 258
Ognl.getValue(Object, Map, Object, Class) line: 470
Ognl.getValue(Object, Map, Object) line: 434
OgnlUtil$2.execute(Object) line: 401
OgnlUtil.compileAndExecute(String, Map<String,Object>, OgnlTask<T>)
line: 442
OgnlUtil.getValue(String, Map<String,Object>, Object) line: 399
OgnlValueStack.getValueUsingOgnl(String) line: 293
OgnlValueStack.tryFindValue(String) line: 276
OgnlValueStack.tryFindValueWhenExpressionIsNotNull(String) line: 258
OgnlValueStack.findValue(String, boolean) line: 238
OgnlValueStack.findValue(String) line: 300
StrutsRequestWrapper.getAttribute(String) line: 94
PrepareOperations.findActionMapping(HttpServletRequest,
HttpServletResponse, boolean) line: 181
PrepareOperations.findActionMapping(HttpServletRequest,
HttpServletResponse) line: 165
StrutsPrepareFilter.doFilter(ServletRequest, ServletResponse,
FilterChain) line: 90
ApplicationFilterChain.internalDoFilter(ServletRequest, ServletResponse)
line: 189
ApplicationFilterChain.doFilter(ServletRequest, ServletResponse) line:
162
...`
Here, the Struts layer attempts to find the {{actionMapping}} to use, which
is first evaluated using OGNL onto the ValueStack - and in this specific case,
there is no such entry in the stack - before it actually gets into the struts
configuration to find the appropriate mapping.
I did spent some time to check how method
{{ognl.ASTChain.getValueBody(OgnlContext, Object)}} works, and I'm actually
puzzled to see that the {{source}} attribute is actually the result of the
previous step in the chain (which can be null, leading to the exception being
raised). But I'm not sure whether this is a problem or a by-design choice (and
I sure don't have enough background onto the OGNL internals to decide).
Would you say that this sequence of event is normal, or is it something that
should not occur?
Let me know, and I'll open another issue - I can reproduce it 100% so it's
easy to investigate if you find it useful...
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
Issue Time Tracking
-------------------
Worklog Id: (was: 680500)
Time Spent: 20m (was: 10m)
> OGNL valid expression is not cached and is parsed over again in some
> situations
> -------------------------------------------------------------------------------
>
> Key: WW-5147
> URL: https://issues.apache.org/jira/browse/WW-5147
> Project: Struts 2
> Issue Type: Bug
> Components: Core
> Affects Versions: 2.5.20
> Reporter: Pascal Davoust
> Priority: Major
> Fix For: 2.6, 2.5.28
>
> Time Spent: 20m
> Remaining Estimate: 0h
>
> Profiling an enterprise application under high load shows an unlikely number
> of invocations to method {{ognl.Ognl.parseExpression}} (representing a
> significant cumulated CPU time), despite having the OGNL expression cache
> enabled.
> Knowing that there is no dynamic expression in this application, this is
> puzzling: once each expression have been encountered, its parsed/compiled
> representation should be cached, avoiding the parsing phase entirely to only
> keep the execution phase.
> After investigation, this is due to the caching logic in method
> {{com.opensymphony.xwork2.ognl.OgnlUtil.compileAndExecute(String, Map<String,
> Object>, OgnlTask<T>}} (same applies to
> {{com.opensymphony.xwork2.ognl.OgnlUtil.compileAndExecuteMethod(String,
> Map<String, Object>, OgnlTask<T>)}} ) :
>
> {code:java}
> private <T> Object compileAndExecute(String expression, Map<String, Object>
> context, OgnlTask<T> task) throws OgnlException {
> Object tree;
> if (enableExpressionCache) {
> tree = expressions.get(expression);
> if (tree == null) {
> tree = Ognl.parseExpression(expression);
> checkEnableEvalExpression(tree, context);
> }
> } else {
> tree = Ognl.parseExpression(expression);
> checkEnableEvalExpression(tree, context);
> }
> final T exec = task.execute(tree);
> // if cache is enabled and it's a valid expression, puts it in
> if (enableExpressionCache) {
> expressions.putIfAbsent(expression, tree);
> }
> return exec;
> } {code}
>
>
> As shown above, on cache miss, the expression is parsed, then executed, and
> added to the cache {+}only after execution{+}.
> Problem is that the execution can fail (especially that Ognl makes use of
> exceptions quite extensively): in this case, the parsed AST is lost and not
> added to the cache.
> As a result, the same expression will go through the cache miss code path
> next time.
>
> Unless I'm mistaken, the AST of the parsed expression could be added to the
> cache right after parsing and validation, and before execution fires: an AST
> is obviously independant from any execution context so it can be reused over
> and over again.
>
> As a proof of concept, I patched our enterprise application with the changes
> above and ran the benchmark again: we experienced a very significant
> improvement in response times and CPU usage, between 10% to 30% decreased
> response times (knowing that these pages also perform time consuming tasks
> such as database updates and search engine lookups).
> I'm happy to provide a PR for you guys to have a look if you deem it worthy.
--
This message was sent by Atlassian Jira
(v8.20.1#820001)
