[ 
https://issues.apache.org/jira/browse/WW-5147?focusedWorklogId=680509&page=com.atlassian.jira.plugin.system.issuetabpanels:worklog-tabpanel#worklog-680509
 ]

ASF GitHub Bot logged work on WW-5147:
--------------------------------------

                Author: ASF GitHub Bot
            Created on: 11/Nov/21 22:37
            Start Date: 11/Nov/21 22:37
    Worklog Time Spent: 10m 
      Work Description: davoustp edited a comment 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 are 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  a stack trace for the `actionMapping` case (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  
       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: 680509)
    Time Spent: 1h 20m  (was: 1h 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: 1h 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)

Reply via email to