groovy
  1. groovy
  2. GROOVY-5249

Avoid unnecessary locking in ClassInfo.getMetaClass

    Details

    • Type: Bug Bug
    • Status: Closed Closed
    • Priority: Critical Critical
    • Resolution: Fixed
    • Affects Version/s: None
    • Fix Version/s: 2.3.0-beta-1, 2.2.3
    • Component/s: groovy-runtime
    • Labels:
      None
    • Environment:
      Linux 64-bit, Java 1.6, Tomcat, Grails
    • Number of attachments :
      2

      Description

      We have a Grails application serving hundreds of requests per second and this seems to be the most critical hot spot for us. Under high load, most threads are blocked in the following call stack:

      "http-apr-8080"-exec-144
      sun.misc.Unsafe.park(Native Method)
      java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)
      java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811)
      java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:842)
      java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1178)
      org.codehaus.groovy.util.LockableObject.lock(LockableObject.java:34)
      org.codehaus.groovy.reflection.ClassInfo.lock(ClassInfo.java:268)
      org.codehaus.groovy.reflection.ClassInfo.getMetaClass(ClassInfo.java:193)
      org.codehaus.groovy.runtime.metaclass.MetaClassRegistryImpl.getMetaClass(MetaClassRegistryImpl.java:214)
      org.codehaus.groovy.runtime.InvokerHelper.getMetaClass(InvokerHelper.java:747)
      org.codehaus.groovy.runtime.InvokerHelper.invokePojoMethod(InvokerHelper.java:780)
      org.codehaus.groovy.runtime.InvokerHelper.invokeMethod(InvokerHelper.java:772)
      org.codehaus.groovy.runtime.typehandling.DefaultTypeTransformation.castToBoolean(DefaultTypeTransformation.java:156)
      org.codehaus.groovy.runtime.typehandling.DefaultTypeTransformation.booleanUnbox(DefaultTypeTransformation.java:65)
      

      Grails uses InvokerHelper a lot, which calls ClassInfo.getMetaClass which uses locking. This is stop-the-world lock affecting all threads (they all hit the same ClassInfo instance). Note that 99,999% of time the locking is useless as nothing is modified (typically all metaclasses getting modified on startup).

      There are several related tickets: GROOVY-3557 and GROOVY-5059, not really solving the issue.

      The solution could be to use more fine-grained locks (ReadWriteLock) or Atomics. Should be easy to implement, but need to isolate modification part from read-only parts.

      Doing so can be a good boost to overall Grails performance.

      1. mc.patch
        2 kB
        blackdrag blackdrag
      2. mc.patch
        1 kB
        blackdrag blackdrag

        Activity

        Hide
        blackdrag blackdrag added a comment -

        If I look at the locking I see that it is done on a per ClassInfo instance base. That means it is possible to get multiple meta classes at the same time even with this locking. The reason why it is a "stop the world lock" for you is probably that all your threads go the boolean#asType path. That means all many of your threads request one and the same ClassInfo instance to then block each other until they are served one-by-one.

        A meta class change relevant for this locking can happen in two cases.
        (1) the older instance was garbage collected (which cannot happen with a modified meta class)
        (2) you changed the meta class manually

        While you say you do (2) at the beginning we have to try to design the core to enable (2) all the time atm.

        Show
        blackdrag blackdrag added a comment - If I look at the locking I see that it is done on a per ClassInfo instance base. That means it is possible to get multiple meta classes at the same time even with this locking. The reason why it is a "stop the world lock" for you is probably that all your threads go the boolean#asType path. That means all many of your threads request one and the same ClassInfo instance to then block each other until they are served one-by-one. A meta class change relevant for this locking can happen in two cases. (1) the older instance was garbage collected (which cannot happen with a modified meta class) (2) you changed the meta class manually While you say you do (2) at the beginning we have to try to design the core to enable (2) all the time atm.
        Hide
        Lari Hotari added a comment -

        Serge, could you provide a test case that shows the problem? I know it's easy to reproduce, but it helps getting this one fixed if you can provide a simple test case the shows the problem. You could also write a test case in pure Java that shows the performance difference to the Groovy version.
        I'd prefer a standalone test class instead of a Grails app that shows the problem. In Grails, ExpandoMetaClass.enableGlobally() is used, so your Groovy test case should probably do that too.

        Show
        Lari Hotari added a comment - Serge, could you provide a test case that shows the problem? I know it's easy to reproduce, but it helps getting this one fixed if you can provide a simple test case the shows the problem. You could also write a test case in pure Java that shows the performance difference to the Groovy version. I'd prefer a standalone test class instead of a Grails app that shows the problem. In Grails, ExpandoMetaClass.enableGlobally() is used, so your Groovy test case should probably do that too.
        Hide
        blackdrag blackdrag added a comment -

        let us think about a Read-WriteLock.... what currently calls lock should do the write lock. Then we can use the internal code to do the read locks.

        Show
        blackdrag blackdrag added a comment - let us think about a Read-WriteLock.... what currently calls lock should do the write lock. Then we can use the internal code to do the read locks.
        Hide
        Serge P. Nekoval added a comment -

        is probably that all your threads go the boolean#asType path. That means all many of your threads request one and the same ClassInfo instance to then block each other until they are served one-by-one.

        That's right. We have lots of calls similar to the following:

        translations.any { it.toLowerCase().contains(text) }
        

        (sometimes even nested). I guess it will request getClassInfo(Boolean.class) inside a long loop.

        From what I see in ClassInfo there are actually two different methods:

        1. getMetaClass()
        2. getMetaClass(Object obj) - checks if instance has an instance-level metaclass assigned, then locks.

        InvokerHelper goes to the second one. Since objects rarely have instance-level metaclasses assigned, there's a high chance to get blocked here.

        Show
        Serge P. Nekoval added a comment - is probably that all your threads go the boolean#asType path. That means all many of your threads request one and the same ClassInfo instance to then block each other until they are served one-by-one. That's right. We have lots of calls similar to the following: translations.any { it.toLowerCase().contains(text) } (sometimes even nested). I guess it will request getClassInfo(Boolean.class) inside a long loop. From what I see in ClassInfo there are actually two different methods: getMetaClass() getMetaClass(Object obj) - checks if instance has an instance-level metaclass assigned, then locks. InvokerHelper goes to the second one. Since objects rarely have instance-level metaclasses assigned, there's a high chance to get blocked here.
        Hide
        blackdrag blackdrag added a comment -

        Serge, could you test if this patch makes a difference for you?

        Show
        blackdrag blackdrag added a comment - Serge, could you test if this patch makes a difference for you?
        blackdrag blackdrag made changes -
        Field Original Value New Value
        Attachment mc.patch [ 58514 ]
        Hide
        Serge P. Nekoval added a comment -

        Hello. I've tried to patch groovy 1.7.10 and got the same problem.
        I see your patch applies to ClassInfo.getMetaClass() while the most critical execution path is ClassInfo.getMetaClass(obj).

        Show
        Serge P. Nekoval added a comment - Hello. I've tried to patch groovy 1.7.10 and got the same problem. I see your patch applies to ClassInfo.getMetaClass() while the most critical execution path is ClassInfo.getMetaClass(obj) .
        Hide
        blackdrag blackdrag added a comment -

        Sorry for the mistake, here is the correct version

        Show
        blackdrag blackdrag added a comment - Sorry for the mistake, here is the correct version
        blackdrag blackdrag made changes -
        Attachment mc.patch [ 58665 ]
        Hide
        Juan Manuel Formoso added a comment -

        Did the fixed patch work? Is it going to be included in a future version?

        Show
        Juan Manuel Formoso added a comment - Did the fixed patch work? Is it going to be included in a future version?
        Hide
        Serge P. Nekoval added a comment -

        Hi, we've upgraded to Grails 2.0 recently, which resolved some of our issues. I will try to squeeze the patch into Grails 2.0 production (it's somewhat tricky) and see how it affects our performance graphs. This will take about a week.

        Show
        Serge P. Nekoval added a comment - Hi, we've upgraded to Grails 2.0 recently, which resolved some of our issues. I will try to squeeze the patch into Grails 2.0 production (it's somewhat tricky) and see how it affects our performance graphs. This will take about a week.
        Hide
        Joe Sondow added a comment - - edited

        FYI, Netflix's internal Grails-based tooling is running into this bug pretty often now. We're rewriting the worst bottleneck parts of our code as needed until the fix comes out. Mostly we're reducing use of find() or any() or findAll() in frequently-called nested closures or nested iterations.

        Show
        Joe Sondow added a comment - - edited FYI, Netflix's internal Grails-based tooling is running into this bug pretty often now. We're rewriting the worst bottleneck parts of our code as needed until the fix comes out. Mostly we're reducing use of find() or any() or findAll() in frequently-called nested closures or nested iterations.
        Hide
        blackdrag blackdrag added a comment -

        Joe, Serge seems not to have the time to test it yet. Can you test the patch?

        Show
        blackdrag blackdrag added a comment - Joe, Serge seems not to have the time to test it yet. Can you test the patch?
        Hide
        Jason Gritman added a comment -

        Hi, I work with Joe at Netflix. We're no longer seeing this problems as frequently after tweaking a few places where we were doing nested find() calls while iterating over a large collection.

        I'll try to test the patch if I get a chance. Since it's somewhat tricky to reproduce the problems, it might be a while before I get to it. Prior to those fixes, this problem was causing our Grails app to become unresponsive almost daily.

        Show
        Jason Gritman added a comment - Hi, I work with Joe at Netflix. We're no longer seeing this problems as frequently after tweaking a few places where we were doing nested find() calls while iterating over a large collection. I'll try to test the patch if I get a chance. Since it's somewhat tricky to reproduce the problems, it might be a while before I get to it. Prior to those fixes, this problem was causing our Grails app to become unresponsive almost daily.
        Hide
        Lari Hotari added a comment -

        There is a thread on Grails mailing list that has interesting findings of performance of calling private helper methods in a closure:
        http://grails.1312388.n4.nabble.com/Thread-Blocking-at-Groovy-ExpandoMetaclass-method-in-a-Grails-App-tp4572990p4574077.html
        (the FilterConfig performance problem is a grails problem, but the later introduced StoryDao example is interesting from Groovy performance point of view)

        Surprisingly a workaround is to call the helper method on "thisObject" prefix. Based on the stacktrace this seems to be some problem in ExpandoMetaClass which is enabled globally in Grails. There seems to be a bug in ExpandoMetaClass's addSuperMethodIfNotOverridden . It only handles ClosureMetaMethod instances.

        Show
        Lari Hotari added a comment - There is a thread on Grails mailing list that has interesting findings of performance of calling private helper methods in a closure: http://grails.1312388.n4.nabble.com/Thread-Blocking-at-Groovy-ExpandoMetaclass-method-in-a-Grails-App-tp4572990p4574077.html (the FilterConfig performance problem is a grails problem, but the later introduced StoryDao example is interesting from Groovy performance point of view) Surprisingly a workaround is to call the helper method on "thisObject" prefix. Based on the stacktrace this seems to be some problem in ExpandoMetaClass which is enabled globally in Grails. There seems to be a bug in ExpandoMetaClass's addSuperMethodIfNotOverridden . It only handles ClosureMetaMethod instances.
        Hide
        Lari Hotari added a comment -

        Joe & Jason, GROOVY-5428 explains the bad performance of find(), any() or findAll() in certain cases. Have you monitored if a large number of Exceptions (ClassCastExceptions) are created?

        Show
        Lari Hotari added a comment - Joe & Jason, GROOVY-5428 explains the bad performance of find(), any() or findAll() in certain cases. Have you monitored if a large number of Exceptions (ClassCastExceptions) are created?
        Hide
        Serge P. Nekoval added a comment -

        We've managed to test a patch, trying it about 2 weeks in production, using Grails 2.0.3 + Groovy 1.8.6 + patch.
        Two things to mention:

        1. Number of busy threads sometimes lowered a bit, but not significantly.
        2. No difference in CPU usage looking at graphs...

        So the patch does, in fact, work. However in our case its effect is fairly minor compared to Grails + Groovy (1.8.x) upgrade.
        I think GROOVY-5059 actually had more impact considering how our code is written.

        Show
        Serge P. Nekoval added a comment - We've managed to test a patch, trying it about 2 weeks in production, using Grails 2.0.3 + Groovy 1.8.6 + patch. Two things to mention: Number of busy threads sometimes lowered a bit, but not significantly. No difference in CPU usage looking at graphs... So the patch does, in fact, work. However in our case its effect is fairly minor compared to Grails + Groovy (1.8.x) upgrade. I think GROOVY-5059 actually had more impact considering how our code is written.
        blackdrag blackdrag made changes -
        Affects Version/s 1.7.x [ 15538 ]
        Hide
        Timur Yusupov added a comment -

        I encountered performance issue caused by locking in ClassInfo.getMetaClass with groovy 1.8.7 when using following construction concurrently:

                    switch (node.name()) {
                        case ['b','s','p','para','sect']:
        ...
        

        Stacktrace is following:

        	  at sun.misc.Unsafe.park(Unsafe.java:-1)
        	  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)
        	  at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811)
        	  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:842)
        	  at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1178)
        	  at org.codehaus.groovy.util.LockableObject.lock(LockableObject.java:34)
        	  at org.codehaus.groovy.reflection.ClassInfo.lock(ClassInfo.java:268)
        	  at org.codehaus.groovy.reflection.ClassInfo.getMetaClass(ClassInfo.java:193)
        	  at org.codehaus.groovy.runtime.metaclass.MetaClassRegistryImpl.getMetaClass(MetaClassRegistryImpl.java:231)
        	  at org.codehaus.groovy.runtime.InvokerHelper.getMetaClass(InvokerHelper.java:747)
        	  at org.codehaus.groovy.runtime.InvokerHelper.invokePojoMethod(InvokerHelper.java:780)
        	  at org.codehaus.groovy.runtime.InvokerHelper.invokeMethod(InvokerHelper.java:772)
        	  at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodN(ScriptBytecodeAdapter.java:164)
        	  at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.isCase(ScriptBytecodeAdapter.java:667)
        
        invokeMethodN(caseExpression.getClass(), caseExpression, "isCase", new Object[]{switchValue})
        

        is locked on ClassInfo for ArrayList, because it uses invokePojoMethod which calls ClassInfo.getMetaClass(obj).

        Show
        Timur Yusupov added a comment - I encountered performance issue caused by locking in ClassInfo.getMetaClass with groovy 1.8.7 when using following construction concurrently: switch (node.name()) { case ['b','s','p','para','sect']: ... Stacktrace is following: at sun.misc.Unsafe.park(Unsafe.java:-1) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156) at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(AbstractQueuedSynchronizer.java:811) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(AbstractQueuedSynchronizer.java:842) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(AbstractQueuedSynchronizer.java:1178) at org.codehaus.groovy.util.LockableObject.lock(LockableObject.java:34) at org.codehaus.groovy.reflection.ClassInfo.lock(ClassInfo.java:268) at org.codehaus.groovy.reflection.ClassInfo.getMetaClass(ClassInfo.java:193) at org.codehaus.groovy.runtime.metaclass.MetaClassRegistryImpl.getMetaClass(MetaClassRegistryImpl.java:231) at org.codehaus.groovy.runtime.InvokerHelper.getMetaClass(InvokerHelper.java:747) at org.codehaus.groovy.runtime.InvokerHelper.invokePojoMethod(InvokerHelper.java:780) at org.codehaus.groovy.runtime.InvokerHelper.invokeMethod(InvokerHelper.java:772) at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodN(ScriptBytecodeAdapter.java:164) at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.isCase(ScriptBytecodeAdapter.java:667) invokeMethodN(caseExpression.getClass(), caseExpression, "isCase" , new Object []{switchValue}) is locked on ClassInfo for ArrayList, because it uses invokePojoMethod which calls ClassInfo.getMetaClass(obj).
        Hide
        blackdrag blackdrag added a comment -

        What I get out of this thread is that we have a general problem with the performance of Groovy-truth from Java code. As a method call from Groovy it would be not such a big problem, since the method would be cached, and not every call will go through getMetaClass in ClassInfo. But in this last trace for example isCase does this, since it is an uncached dynamic call

        has someone reading in this thread any idea how to prevent that? I could apply some logic from the primitive optimizations, but EMC is disabling that. I could try hand made call site caching in the Java code... that would help in some cases maybe... in JDK 1.7 I could leverage ClassValue and avoid the locking probably... But that doesn't help in Groovy 1.8 and not on pre jdk7 vms

        Show
        blackdrag blackdrag added a comment - What I get out of this thread is that we have a general problem with the performance of Groovy-truth from Java code. As a method call from Groovy it would be not such a big problem, since the method would be cached, and not every call will go through getMetaClass in ClassInfo. But in this last trace for example isCase does this, since it is an uncached dynamic call has someone reading in this thread any idea how to prevent that? I could apply some logic from the primitive optimizations, but EMC is disabling that. I could try hand made call site caching in the Java code... that would help in some cases maybe... in JDK 1.7 I could leverage ClassValue and avoid the locking probably... But that doesn't help in Groovy 1.8 and not on pre jdk7 vms
        Hide
        blackdrag blackdrag added a comment -

        I added several changes that should help with the usage of Groovy Truth in internal iterating methods such as any, find and grep. The changes I did will not help with the switch-case Timur reported. What I did was adding a caching for the meta methods involved, especially Closure#call and asBoolean. The logic for Groovy-Truth is unchanged, only faster I hope

        I guess for the switch-case we need to think a bit more about what to do. But for example Serge should see an inprovement.

        Show
        blackdrag blackdrag added a comment - I added several changes that should help with the usage of Groovy Truth in internal iterating methods such as any, find and grep. The changes I did will not help with the switch-case Timur reported. What I did was adding a caching for the meta methods involved, especially Closure#call and asBoolean. The logic for Groovy-Truth is unchanged, only faster I hope I guess for the switch-case we need to think a bit more about what to do. But for example Serge should see an inprovement.
        blackdrag blackdrag made changes -
        Parent GROOVY-2503 [ 61571 ]
        Issue Type Improvement [ 4 ] Sub-task [ 7 ]
        Hide
        Lari Hotari added a comment -

        This is also a problem in Grails 2.2.0 / Groovy 2.0.5 . See Grails mailing list thread for more details: http://grails.1312388.n4.nabble.com/Grails-performance-restriction-tt4642061.html . It looks like InvokerHelper.getProperty triggers this problem when POJOs are used. Making POJOs extend GroovyObjectSupport (or implement GroovyObject) is one workaround for this problem before this issue gets fixed.

        Show
        Lari Hotari added a comment - This is also a problem in Grails 2.2.0 / Groovy 2.0.5 . See Grails mailing list thread for more details: http://grails.1312388.n4.nabble.com/Grails-performance-restriction-tt4642061.html . It looks like InvokerHelper.getProperty triggers this problem when POJOs are used. Making POJOs extend GroovyObjectSupport (or implement GroovyObject) is one workaround for this problem before this issue gets fixed.
        Hide
        Lari Hotari added a comment -

        Graeme suggested another workaround in the Grails mailing list thread: "GroovySystem.keepJavaMetaClasses = true" setting might help. @CompileStatic does too.

        Show
        Lari Hotari added a comment - Graeme suggested another workaround in the Grails mailing list thread : "GroovySystem.keepJavaMetaClasses = true" setting might help. @CompileStatic does too.
        blackdrag blackdrag made changes -
        Affects Version/s 1.8.x [ 15750 ]
        blackdrag blackdrag made changes -
        Component/s groovy-runtime [ 16250 ]
        Show
        Lari Hotari added a comment - PR https://github.com/groovy/groovy-core/pull/342
        Hide
        Lari Hotari added a comment -

        PR updated, patch available at url https://github.com/groovy/groovy-core/pull/342.patch if someone wants to test the patch with other groovy version branches.

        Show
        Lari Hotari added a comment - PR updated, patch available at url https://github.com/groovy/groovy-core/pull/342.patch if someone wants to test the patch with other groovy version branches.
        Show
        Lari Hotari added a comment - patch backported to Groovy 2.0.8 : https://github.com/lhotari/groovy-core/compare/GROOVY_2_0_8...GROOVY-5249-backport.patch , commits: https://github.com/lhotari/groovy-core/compare/GROOVY_2_0_8...GROOVY-5249-backport
        Hide
        Fedor Belov added a comment -

        Hi. We have applied this patch on our production server and it works much, much better

        Show
        Fedor Belov added a comment - Hi. We have applied this patch on our production server and it works much, much better
        Hide
        blackdrag blackdrag added a comment -

        you mean the change from github?

        Show
        blackdrag blackdrag added a comment - you mean the change from github?
        Hide
        Fedor Belov added a comment - - edited

        this one -> https://github.com/lhotari/groovy-core/compare/GROOVY_2_0_8...GROOVY-5249-backport.patch
        but it doesn't really differ from unofficial one - https://jira.codehaus.org/secure/attachment/58665/mc.patch - it also works. Just it breaks 1 of 6000 groovy tests

        Show
        Fedor Belov added a comment - - edited this one -> https://github.com/lhotari/groovy-core/compare/GROOVY_2_0_8...GROOVY-5249-backport.patch but it doesn't really differ from unofficial one - https://jira.codehaus.org/secure/attachment/58665/mc.patch - it also works. Just it breaks 1 of 6000 groovy tests
        Hide
        blackdrag blackdrag added a comment -

        I applied the patch in a slightly modified version

        Show
        blackdrag blackdrag added a comment - I applied the patch in a slightly modified version
        blackdrag blackdrag made changes -
        Resolution Fixed [ 1 ]
        Fix Version/s 2.3.0 [ 19608 ]
        Fix Version/s 2.2.3 [ 20130 ]
        Assignee blackdrag blackdrag [ blackdrag ]
        Status Open [ 1 ] Resolved [ 5 ]
        blackdrag blackdrag made changes -
        Affects Version/s 2.x [ 17013 ]
        blackdrag blackdrag made changes -
        Issue Type Sub-task [ 7 ] Bug [ 1 ]
        Parent GROOVY-2503 [ 61571 ]
        Paul King made changes -
        Status Resolved [ 5 ] Closed [ 6 ]

          People

          • Assignee:
            blackdrag blackdrag
            Reporter:
            Serge P. Nekoval
          • Votes:
            13 Vote for this issue
            Watchers:
            14 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved: