You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@struts.apache.org by "Lukasz Lenart (JIRA)" <ji...@apache.org> on 2017/08/01 09:51:08 UTC

[jira] [Resolved] (WW-4817) Threads get blocked due to unnecessary synchronization in OgnlRuntime

     [ https://issues.apache.org/jira/browse/WW-4817?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Lukasz Lenart resolved WW-4817.
-------------------------------
    Resolution: Fixed
      Assignee: Lukasz Lenart

> Threads get blocked due to unnecessary synchronization in OgnlRuntime
> ---------------------------------------------------------------------
>
>                 Key: WW-4817
>                 URL: https://issues.apache.org/jira/browse/WW-4817
>             Project: Struts 2
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 2.3.32, 2.5.12
>            Reporter: Santhana Preethi J
>            Assignee: Lukasz Lenart
>             Fix For: 2.3.34, 2.5.13
>
>         Attachments: ThreadBlock.war, threadDump.txt
>
>
> In multi-threaded scenario, due to unnecessary synchronization in invokeMethod method in OgnlRuntime class all threads except the first go to BLOCKED state.
> {code:java}
> public static Object invokeMethod(Object target, Method method, Object[] argsArray)
>     throws InvocationTargetException, IllegalAccessException
>   { 
> .......
>  synchronized (method) {
>       if ((_methodAccessCache.get(method) == null) || (_methodAccessCache.get(method) == Boolean.TRUE))
>       {
>         syncInvoke = true;
>       }
> .......
>     }
> {code}
> Because *syncInvoke* becomes true for the first thread irrespective of whether the method is public or not, all other threads go to block state till the first thread leaves the method invocation synchronization block.
> Attached threadDump of the blocked threads waiting to lock the monitor 0x00000006c690e5b8 even though the method invoked by the action is public.
> {code:java}
> "_###_Thread-1499929571461_###_http-nio-8443-exec-20" #374 daemon prio=5 os_prio=0 tid=0x00007f830513a000 nid=0x49c1 waiting for monitor entry [0x00007f7e9c7c2000]
>    java.lang.Thread.State: BLOCKED (on object monitor)
> 	at ognl.OgnlRuntime.invokeMethod(OgnlRuntime.java:826)
> 	- waiting to lock <0x00000006c690e5b8> (a java.lang.reflect.Method)
> 	at ognl.OgnlRuntime.callAppropriateMethod(OgnlRuntime.java:1294)
> 	at ognl.ObjectMethodAccessor.callMethod(ObjectMethodAccessor.java:68)
> 	at com.opensymphony.xwork2.ognl.accessor.XWorkMethodAccessor.callMethodWithDebugInfo(XWorkMethodAccessor.java:117)
> 	at com.opensymphony.xwork2.ognl.accessor.XWorkMethodAccessor.callMethod(XWorkMethodAccessor.java:108)
> 	at ognl.OgnlRuntime.callMethod(OgnlRuntime.java:1370)
> 	at ognl.ASTMethod.getValueBody(ASTMethod.java:91)
> 	at ognl.SimpleNode.evaluateGetValueBody(SimpleNode.java:212)
> 	at ognl.SimpleNode.getValue(SimpleNode.java:258)
> 	at ognl.Ognl.getValue(Ognl.java:467)
> 	at ognl.Ognl.getValue(Ognl.java:431)
> 	at com.opensymphony.xwork2.ognl.OgnlUtil$3.execute(OgnlUtil.java:352)
> 	at com.opensymphony.xwork2.ognl.OgnlUtil.compileAndExecuteMethod(OgnlUtil.java:404)
> 	at com.opensymphony.xwork2.ognl.OgnlUtil.callMethod(OgnlUtil.java:350)
> 	at com.opensymphony.xwork2.DefaultActionInvocation.invokeAction(DefaultActionInvocation.java:430)
> 	at com.opensymphony.xwork2.DefaultActionInvocation.invokeActionOnly(DefaultActionInvocation.java:290)
> 	at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:251)
> 	at com.opensymphony.xwork2.interceptor.DefaultWorkflowInterceptor.doIntercept(DefaultWorkflowInterceptor.java:168)
> 	.........
> 	at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:245)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> 	at java.lang.reflect.Method.invoke(Method.java:498)
> 	..........
> 	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:141)
> 	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
> 	at org.apache.catalina.authenticator.SingleSignOn.invoke(SingleSignOn.java:240)
> 	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
> 	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:502)
> 	at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1132)
> 	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:684)
> 	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1533)
> 	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1489)
> 	- locked <0x00000006c5249d98> (a org.apache.tomcat.util.net.NioChannel)
> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> 	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
> 	at java.lang.Thread.run(Thread.java:748)
> "Thread-1499929605769_###_Thread-1499929605766_###_http-nio-8443-exec-19" #373 daemon prio=5 os_prio=0 tid=0x00007f8305138000 nid=0x49c0 waiting for monitor entry [0x00007f7e9c8c3000]
>    java.lang.Thread.State: BLOCKED (on object monitor)
> 	at ognl.OgnlRuntime.invokeMethod(OgnlRuntime.java:826)
> 	- waiting to lock <0x00000006c690e5b8> (a java.lang.reflect.Method)
> 	at ognl.OgnlRuntime.callAppropriateMethod(OgnlRuntime.java:1294)
> 	at ognl.ObjectMethodAccessor.callMethod(ObjectMethodAccessor.java:68)
> 	at com.opensymphony.xwork2.ognl.accessor.XWorkMethodAccessor.callMethodWithDebugInfo(XWorkMethodAccessor.java:117)
> 	at com.opensymphony.xwork2.ognl.accessor.XWorkMethodAccessor.callMethod(XWorkMethodAccessor.java:108)
> 	at ognl.OgnlRuntime.callMethod(OgnlRuntime.java:1370)
> 	at ognl.ASTMethod.getValueBody(ASTMethod.java:91)
> 	at ognl.SimpleNode.evaluateGetValueBody(SimpleNode.java:212)
> 	at ognl.SimpleNode.getValue(SimpleNode.java:258)
> 	at ognl.Ognl.getValue(Ognl.java:467)
> 	at ognl.Ognl.getValue(Ognl.java:431)
> 	at com.opensymphony.xwork2.ognl.OgnlUtil$3.execute(OgnlUtil.java:352)
> 	at com.opensymphony.xwork2.ognl.OgnlUtil.compileAndExecuteMethod(OgnlUtil.java:404)
> 	at com.opensymphony.xwork2.ognl.OgnlUtil.callMethod(OgnlUtil.java:350)
> 	at com.opensymphony.xwork2.DefaultActionInvocation.invokeAction(DefaultActionInvocation.java:430)
> 	at com.opensymphony.xwork2.DefaultActionInvocation.invokeActionOnly(DefaultActionInvocation.java:290)
> 	at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:251)
> 	........
> 	at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:245)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> 	at java.lang.reflect.Method.invoke(Method.java:498)
> 	.........
> 	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:141)
> 	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
> 	at org.apache.catalina.authenticator.SingleSignOn.invoke(SingleSignOn.java:240)
> 	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
> 	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:502)
> 	at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1132)
> 	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:684)
> 	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1533)
> 	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1489)
> 	- locked <0x00000006c844cea8> (a org.apache.tomcat.util.net.NioChannel)
> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> 	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
> 	at java.lang.Thread.run(Thread.java:748)
> "Thread-1499929651452_###_Thread-1499929651449_###_http-nio-8443-exec-17" #371 daemon prio=5 os_prio=0 tid=0x00007f8305134000 nid=0x49be waiting for monitor entry [0x00007f7e9cac4000]
>    java.lang.Thread.State: BLOCKED (on object monitor)
> 	at ognl.OgnlRuntime.invokeMethod(OgnlRuntime.java:826)
> 	- waiting to lock <0x00000006c690e5b8> (a java.lang.reflect.Method)
> 	at ognl.OgnlRuntime.callAppropriateMethod(OgnlRuntime.java:1294)
> 	at ognl.ObjectMethodAccessor.callMethod(ObjectMethodAccessor.java:68)
> 	at com.opensymphony.xwork2.ognl.accessor.XWorkMethodAccessor.callMethodWithDebugInfo(XWorkMethodAccessor.java:117)
> 	at com.opensymphony.xwork2.ognl.accessor.XWorkMethodAccessor.callMethod(XWorkMethodAccessor.java:108)
> 	at ognl.OgnlRuntime.callMethod(OgnlRuntime.java:1370)
> 	at ognl.ASTMethod.getValueBody(ASTMethod.java:91)
> 	at ognl.SimpleNode.evaluateGetValueBody(SimpleNode.java:212)
> 	at ognl.SimpleNode.getValue(SimpleNode.java:258)
> 	at ognl.Ognl.getValue(Ognl.java:467)
> 	at ognl.Ognl.getValue(Ognl.java:431)
> 	at com.opensymphony.xwork2.ognl.OgnlUtil$3.execute(OgnlUtil.java:352)
> 	at com.opensymphony.xwork2.ognl.OgnlUtil.compileAndExecuteMethod(OgnlUtil.java:404)
> 	at com.opensymphony.xwork2.ognl.OgnlUtil.callMethod(OgnlUtil.java:350)
> 	at com.opensymphony.xwork2.DefaultActionInvocation.invokeAction(DefaultActionInvocation.java:430)
> 	at com.opensymphony.xwork2.DefaultActionInvocation.invokeActionOnly(DefaultActionInvocation.java:290)
> 	at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:251)
> 	........
> 	at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:245)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> 	at java.lang.reflect.Method.invoke(Method.java:498)
> 	.........
> 	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:141)
> 	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
> 	at org.apache.catalina.authenticator.SingleSignOn.invoke(SingleSignOn.java:240)
> 	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
> 	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:502)
> 	at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1132)
> 	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:684)
> 	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1533)
> 	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1489)
> 	- locked <0x00000006c8605150> (a org.apache.tomcat.util.net.NioChannel)
> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> 	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
> 	at java.lang.Thread.run(Thread.java:748)
> "Thread-1499929544435_###_Thread-1499929544432_###_http-nio-8443-exec-13" #367 daemon prio=5 os_prio=0 tid=0x00007f830512c800 nid=0x49ba runnable [0x00007f7e9cec6000]
>    java.lang.Thread.State: RUNNABLE
> 	at java.net.SocketInputStream.socketRead0(Native Method)
> 	at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
> 	at java.net.SocketInputStream.read(SocketInputStream.java:171)
> 	at java.net.SocketInputStream.read(SocketInputStream.java:141)
> 	at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:114)
> 	at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:161)
> 	at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:189)
> 	- locked <0x00000006c7201d08> (a com.mysql.jdbc.util.ReadAheadInputStream)
> 	at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3014)
> 	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3467)
> 	at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3456)
> 	at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3997)
> 	at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2468)
> 	at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2629)
> 	at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2713)
> 	- locked <0x00000006c6a0cdd0> (a com.mysql.jdbc.JDBC4Connection)
> 	at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2663)
> 	at com.mysql.jdbc.StatementImpl.executeQuery(StatementImpl.java:1599)
> 	- locked <0x00000006c6a0cdd0> (a com.mysql.jdbc.JDBC4Connection)
> 	.........
> 	at sun.reflect.GeneratedMethodAccessor44.invoke(Unknown Source)
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> 	at java.lang.reflect.Method.invoke(Method.java:498)
> 	.........
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> 	at java.lang.reflect.Method.invoke(Method.java:498)
> 	..........
> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> 	at java.lang.reflect.Method.invoke(Method.java:498)
> 	at ognl.OgnlRuntime.invokeMethod(OgnlRuntime.java:871)
> 	- locked <0x00000006c690e5b8> (a java.lang.reflect.Method)
> 	at ognl.OgnlRuntime.callAppropriateMethod(OgnlRuntime.java:1294)
> 	at ognl.ObjectMethodAccessor.callMethod(ObjectMethodAccessor.java:68)
> 	at com.opensymphony.xwork2.ognl.accessor.XWorkMethodAccessor.callMethodWithDebugInfo(XWorkMethodAccessor.java:117)
> 	at com.opensymphony.xwork2.ognl.accessor.XWorkMethodAccessor.callMethod(XWorkMethodAccessor.java:108)
> 	at ognl.OgnlRuntime.callMethod(OgnlRuntime.java:1370)
> 	at ognl.ASTMethod.getValueBody(ASTMethod.java:91)
> 	at ognl.SimpleNode.evaluateGetValueBody(SimpleNode.java:212)
> 	at ognl.SimpleNode.getValue(SimpleNode.java:258)
> 	at ognl.Ognl.getValue(Ognl.java:467)
> 	at ognl.Ognl.getValue(Ognl.java:431)
> 	at com.opensymphony.xwork2.ognl.OgnlUtil$3.execute(OgnlUtil.java:352)
> 	at com.opensymphony.xwork2.ognl.OgnlUtil.compileAndExecuteMethod(OgnlUtil.java:404)
> 	at com.opensymphony.xwork2.ognl.OgnlUtil.callMethod(OgnlUtil.java:350)
> 	at com.opensymphony.xwork2.DefaultActionInvocation.invokeAction(DefaultActionInvocation.java:430)
> 	at com.opensymphony.xwork2.DefaultActionInvocation.invokeActionOnly(DefaultActionInvocation.java:290)
> 	at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:251)
> 	..........
> 	at com.opensymphony.xwork2.DefaultActionInvocation.invoke(DefaultActionInvocation.java:245)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> 	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> 	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> 	at java.lang.reflect.Method.invoke(Method.java:498)
> 	...........
> 	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:141)
> 	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:79)
> 	at org.apache.catalina.authenticator.SingleSignOn.invoke(SingleSignOn.java:240)
> 	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:88)
> 	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:502)
> 	at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1132)
> 	at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:684)
> 	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1533)
> 	at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.run(NioEndpoint.java:1489)
> 	- locked <0x00000006c52e67a8> (a org.apache.tomcat.util.net.NioChannel)
> 	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> 	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
> 	at java.lang.Thread.run(Thread.java:748)
> {code}
> Modified the syncInvoke checks to prevent this unnecessary blocking
> {code:java}
>  public static Object invokeMethod(Object target, Method method, Object[] argsArray)
>     throws InvocationTargetException, IllegalAccessException
>   {
>     boolean syncInvoke = false;
>     boolean checkPermission = false;
>     boolean wasAccessible = true;
>     synchronized (method) {
>       if ((_methodAccessCache.get(method) == null))
>       {
>         if ((!Modifier.isPublic(method.getModifiers())) || (!Modifier.isPublic(method.getDeclaringClass().getModifiers())))
>         {
>           if (!(wasAccessible = method.isAccessible()))
>           {
>              method.setAccessible(true);
>             _methodAccessCache.put(method, Boolean.TRUE);
>           }
>           else {
>             _methodAccessCache.put(method, Boolean.FALSE);
>           }
>         }
>         else {
>           _methodAccessCache.put(method, Boolean.FALSE);
>         }
>       }
>       if (_methodAccessCache.get(method) == Boolean.TRUE))
>       {
>         syncInvoke = true;
>       }
>       if (((_securityManager != null) && (_methodPermCache.get(method) == null)) || (_methodPermCache.get(method) == Boolean.FALSE))
>       {
>         checkPermission = true;
>       }
>     }
>     Object result;
>     if (syncInvoke)
>     {
>       synchronized (method)
>       {
>         if (checkPermission)
>         {
>           try
>           {
>             _securityManager.checkPermission(getPermission(method));
>             _methodPermCache.put(method, Boolean.TRUE);
>           } catch (SecurityException ex) {
>             _methodPermCache.put(method, Boolean.FALSE);
>             throw new IllegalAccessException("Method [" + method + "] cannot be accessed.");
>           }
>         }
>         Object result = method.invoke(target, argsArray);
>         if (!wasAccessible)
>         {
>           method.setAccessible(false);
>         }
>       }
>     }
>     else {
>       if (checkPermission)
>       {
>         try
>         {
>           _securityManager.checkPermission(getPermission(method));
>           _methodPermCache.put(method, Boolean.TRUE);
>         } catch (SecurityException ex) {
>           _methodPermCache.put(method, Boolean.FALSE);
>           throw new IllegalAccessException("Method [" + method + "] cannot be accessed.");
>         }
>       }
>       result = method.invoke(target, argsArray);
>     }
>     return result;
>   }
> {code}



--
This message was sent by Atlassian JIRA
(v6.4.14#64029)