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. threadDump.txt
          53 kB
          Santhana Preethi J
        2. ThreadBlock.war
          4.03 MB
          Santhana Preethi J

        Issue Links

          relates to

          Dependency - Issue is dependent on ... WW-4832 Upgrade to OGNL 3.0.21

          • Major - Major loss of function.
          • Closed

          Dependency - Issue is dependent on ... WW-4833 Upgrade to OGNL 3.1.15

          • Major - Major loss of function.
          • Closed
          links to

          Web Link ognl pull #36

          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: