Uploaded image for project: 'Struts 2'
  1. Struts 2
  2. WW-4817

Threads get blocked due to unnecessary synchronization in OgnlRuntime

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Closed
    • Major
    • Resolution: Fixed
    • 2.3.32, 2.5.12
    • 2.3.34, 2.5.13
    • Core
    • None

    Description

      In multi-threaded scenario, due to unnecessary synchronization in invokeMethod method in OgnlRuntime class all threads except the first go to BLOCKED state.

      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;
            }
      .......
          }
      

      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.

      "_###_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)
      
      

      Modified the syncInvoke checks to prevent this unnecessary blocking

       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;
        }
      
      

      Attachments

        1. ThreadBlock.war
          4.03 MB
          Santhana Preethi J
        2. threadDump.txt
          53 kB
          Santhana Preethi J

        Issue Links

          Activity

            People

              lukaszlenart Lukasz Lenart
              Preethi Santhana Preethi J
              Votes:
              1 Vote for this issue
              Watchers:
              6 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: