Quantcast

Thread Blocking at Groovy ExpandoMetaclass method in a Grails App

classic Classic list List threaded Threaded
24 messages Options
12
Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Thread Blocking at Groovy ExpandoMetaclass method in a Grails App

Lari Hotari -

So you are using the "poor man's profiling" method. :) Sometimes it's a nice way to do profiling.

I think you need a real profiler if you want to get more accurate results. For example, it's quite hard to find the "10 top blockers" in your solution without a profiler.

Regards,

Lari

btw. A profiler can also show how many exceptions are created/thrown. Normal execution flow should not throw/catch exceptions since they are relatively heavy weight.



23.04.2012 15:41, Gopinath, Dhanush wrote:

Hi,

 

Unfortunately we do not use Yourkit. We take the JStack output and analyse it in TDA (  Thread Dump Analyser)

 

Dhanush

 

From: Lari Hotari [[hidden email]]
Sent: 23 April 2012 18:05
To: Gopinath, Dhanush
Cc: [hidden email]
Subject: Re: [grails-user] Thread Blocking at Groovy ExpandoMetaclass method in a Grails App

 

Hi,

Is this one a "top blocker" and can you reproduce the performance problem (is it constantly blocking in this method)?

I've been using YourKit Java Profiler for profiling (in sampling mode). To get the "top blockers", I go to "Monitor Usage" tab and sort the results by "count".

I've described my way to profile Grails in this thread: http://grails.1312388.n4.nabble.com/Help-with-a-benchmark-tp3943263p3971929.html . To find out what is blocking, I usually disable all special measurements/probes in YJP (-agentpath:/opt/yjp/bin/linux-x86-32/libyjpagent.so=delay=30000,disableall,sampling,onexit=snapshot) and only enable monitor profiling.

What method are you using to find out what is blocking?


Regards,

Lari



23.04.2012 15:02, Gopinath, Dhanush wrote:

Making the method public also improves the performance, but not sure if this is the correct workaround.

 

I also ran into this issue while we increased the load a bit. TeaContextSport is a class inside a plugin which we are using to access some legacy application, and line no 16 tries to invoke an method in the legacy code. But the thread gets Blocked

 

 

"http-thread-pool-8080(470)" daemon prio=6 tid=0x00000000160d5000 nid=0x19fc waiting for monitor entry [0x000000003ca2b000]

   java.lang.Thread.State: BLOCKED (on object monitor)

        at org.codehaus.groovy.reflection.GeneratedMetaMethod$Proxy.proxy(GeneratedMetaMethod.java:78)

        - waiting to lock <a moz-do-not-send="true" href="monitor://%3c0x00000007ccaa5790%3e"><0x00000007ccaa5790> (a org.codehaus.groovy.reflection.GeneratedMetaMethod$Proxy)

        at org.codehaus.groovy.reflection.GeneratedMetaMethod$Proxy.doMethodInvoke(GeneratedMetaMethod.java:70)

        at groovy.lang.MetaClassImpl.getProperty(MetaClassImpl.java:1604)

        at groovy.lang.ExpandoMetaClass.getProperty(ExpandoMetaClass.java:1140)

        at groovy.lang.MetaClassImpl.getProperty(MetaClassImpl.java:3332)

        at groovy.lang.ExpandoMetaClass.getProperty(ExpandoMetaClass.java:1152)

        at org.codehaus.groovy.runtime.InvokerHelper.getProperty(InvokerHelper.java:161)

        at org.codehaus.groovy.runtime.callsite.PojoMetaClassGetPropertySite.callGetProperty(PojoMetaClassGetPropertySite.java:41)

        at com.espn.tea.client.TeaContextSport.invokeMethod(TeaContextSport.groovy:16)

        at groovy.lang.GroovyObject$invokeMethod.call(Unknown Source)

        at com.espn.tea.client.TeaContextClient.invokeMethod(TeaContextClient.groovy:28)

        at org.codehaus.groovy.runtime.callsite.PogoMetaClassSite.call(PogoMetaClassSite.java:45)

        at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:116)

        at com.espni.domain.dao.soccer.TeamDao.getTeamById(TeamDao.groovy:61)

        at com.espni.domain.dao.soccer.TeamDao.getTeamById(TeamDao.groovy:55)

        at com.espni.domain.dao.soccer.TeamDao$getTeamById.call(Unknown Source)

        at com.espni.domain.dao.soccer.GameDao.getGame(GameDao.groovy:38)

        at com.espni.domain.dao.soccer.GameDao$getGame.callCurrent(Unknown Source)

        at com.espni.domain.dao.soccer.GameDao.getGameById(GameDao.groovy:94)

        at sun.reflect.GeneratedMethodAccessor1551.invoke(Unknown Source)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

        at java.lang.reflect.Method.invoke(Method.java:597)

        at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:90)

        at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:233)

        at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1071)

        at groovy.lang.ExpandoMetaClass.invokeMethod(ExpandoMetaClass.java:1110)

        at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:901)

        at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1016)

        at groovy.lang.ExpandoMetaClass.invokeMethod(ExpandoMetaClass.java:1110)

        at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:901)

        at org.codehaus.groovy.runtime.callsite.PogoMetaClassSite.callCurrent(PogoMetaClassSite.java:66)

        at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:141)

        at com.espni.domain.dao.soccer.GameDao$_getGamesByLeagueSeason_closure1.doCall(GameDao.groovy:109)

        at sun.reflect.GeneratedMethodAccessor1548.invoke(Unknown Source)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

        at java.lang.reflect.Method.invoke(Method.java:597)

        at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:90)

 

 


Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

RE: Thread Blocking at Groovy ExpandoMetaclass method in a Grails App

Dhanush Gopinath

Yea J Will try to profile with Yourkit and update

 

From: Lari Hotari [mailto:[hidden email]]
Sent: 23 April 2012 18:41
To: Gopinath, Dhanush
Cc: [hidden email]
Subject: Re: [grails-user] Thread Blocking at Groovy ExpandoMetaclass method in a Grails App

 


So you are using the "poor man's profiling" method. :) Sometimes it's a nice way to do profiling.

I think you need a real profiler if you want to get more accurate results. For example, it's quite hard to find the "10 top blockers" in your solution without a profiler.

Regards,

Lari

btw. A profiler can also show how many exceptions are created/thrown. Normal execution flow should not throw/catch exceptions since they are relatively heavy weight.



23.04.2012 15:41, Gopinath, Dhanush wrote:

Hi,

 

Unfortunately we do not use Yourkit. We take the JStack output and analyse it in TDA (  Thread Dump Analyser)

 

Dhanush

 

From: Lari Hotari [[hidden email]]
Sent: 23 April 2012 18:05
To: Gopinath, Dhanush
Cc: [hidden email]
Subject: Re: [grails-user] Thread Blocking at Groovy ExpandoMetaclass method in a Grails App

 

Hi,

Is this one a "top blocker" and can you reproduce the performance problem (is it constantly blocking in this method)?

I've been using YourKit Java Profiler for profiling (in sampling mode). To get the "top blockers", I go to "Monitor Usage" tab and sort the results by "count".

I've described my way to profile Grails in this thread: http://grails.1312388.n4.nabble.com/Help-with-a-benchmark-tp3943263p3971929.html . To find out what is blocking, I usually disable all special measurements/probes in YJP (-agentpath:/opt/yjp/bin/linux-x86-32/libyjpagent.so=delay=30000,disableall,sampling,onexit=snapshot) and only enable monitor profiling.

What method are you using to find out what is blocking?


Regards,

Lari



23.04.2012 15:02, Gopinath, Dhanush wrote:

Making the method public also improves the performance, but not sure if this is the correct workaround.

 

I also ran into this issue while we increased the load a bit. TeaContextSport is a class inside a plugin which we are using to access some legacy application, and line no 16 tries to invoke an method in the legacy code. But the thread gets Blocked

 

 

"http-thread-pool-8080(470)" daemon prio=6 tid=0x00000000160d5000 nid=0x19fc waiting for monitor entry [0x000000003ca2b000]

   java.lang.Thread.State: BLOCKED (on object monitor)

        at org.codehaus.groovy.reflection.GeneratedMetaMethod$Proxy.proxy(GeneratedMetaMethod.java:78)

        - waiting to lock <a href="monitor://%3c0x00000007ccaa5790%3e"><0x00000007ccaa5790> (a org.codehaus.groovy.reflection.GeneratedMetaMethod$Proxy)

        at org.codehaus.groovy.reflection.GeneratedMetaMethod$Proxy.doMethodInvoke(GeneratedMetaMethod.java:70)

        at groovy.lang.MetaClassImpl.getProperty(MetaClassImpl.java:1604)

        at groovy.lang.ExpandoMetaClass.getProperty(ExpandoMetaClass.java:1140)

        at groovy.lang.MetaClassImpl.getProperty(MetaClassImpl.java:3332)

        at groovy.lang.ExpandoMetaClass.getProperty(ExpandoMetaClass.java:1152)

        at org.codehaus.groovy.runtime.InvokerHelper.getProperty(InvokerHelper.java:161)

        at org.codehaus.groovy.runtime.callsite.PojoMetaClassGetPropertySite.callGetProperty(PojoMetaClassGetPropertySite.java:41)

        at com.espn.tea.client.TeaContextSport.invokeMethod(TeaContextSport.groovy:16)

        at groovy.lang.GroovyObject$invokeMethod.call(Unknown Source)

        at com.espn.tea.client.TeaContextClient.invokeMethod(TeaContextClient.groovy:28)

        at org.codehaus.groovy.runtime.callsite.PogoMetaClassSite.call(PogoMetaClassSite.java:45)

        at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:116)

        at com.espni.domain.dao.soccer.TeamDao.getTeamById(TeamDao.groovy:61)

        at com.espni.domain.dao.soccer.TeamDao.getTeamById(TeamDao.groovy:55)

        at com.espni.domain.dao.soccer.TeamDao$getTeamById.call(Unknown Source)

        at com.espni.domain.dao.soccer.GameDao.getGame(GameDao.groovy:38)

        at com.espni.domain.dao.soccer.GameDao$getGame.callCurrent(Unknown Source)

        at com.espni.domain.dao.soccer.GameDao.getGameById(GameDao.groovy:94)

        at sun.reflect.GeneratedMethodAccessor1551.invoke(Unknown Source)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

        at java.lang.reflect.Method.invoke(Method.java:597)

        at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:90)

        at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:233)

        at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1071)

        at groovy.lang.ExpandoMetaClass.invokeMethod(ExpandoMetaClass.java:1110)

        at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:901)

        at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1016)

        at groovy.lang.ExpandoMetaClass.invokeMethod(ExpandoMetaClass.java:1110)

        at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:901)

        at org.codehaus.groovy.runtime.callsite.PogoMetaClassSite.callCurrent(PogoMetaClassSite.java:66)

        at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:141)

        at com.espni.domain.dao.soccer.GameDao$_getGamesByLeagueSeason_closure1.doCall(GameDao.groovy:109)

        at sun.reflect.GeneratedMethodAccessor1548.invoke(Unknown Source)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

        at java.lang.reflect.Method.invoke(Method.java:597)

        at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:90)

 

 

 

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

RE: Thread Blocking at Groovy ExpandoMetaclass method in a Grails App

Dhanush Gopinath
In reply to this post by Lari Hotari -

Hi Lari,

 

Now we are consistently getting this exception when we increase the load:

 

"http-thread-pool-8080(350)" daemon prio=6 tid=0x0000000017a20000 nid=0x1518 waiting on condition [0x000000003315b000]

   java.lang.Thread.State: WAITING (parking)

      at sun.misc.Unsafe.park(Native Method)

      - parking to wait for  <0x00000007d100a0f0> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)

      at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)

      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 java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(ReentrantReadWriteLock.java:807)

      at groovy.lang.ExpandoMetaClass.performOperationOnMetaClass(ExpandoMetaClass.java:809)

      - locked <0x00000007d1009a50> (a groovy.lang.ExpandoMetaClass)

      at groovy.lang.ExpandoMetaClass.addSuperMethodIfNotOverridden(ExpandoMetaClass.java:513)

      at groovy.lang.ExpandoMetaClass.onSuperMethodFoundInHierarchy(ExpandoMetaClass.java:394)

      at groovy.lang.MetaClassImpl.invokeMissingMethod(MetaClassImpl.java:813)

      at groovy.lang.MetaClassImpl.invokePropertyOrMissing(MetaClassImpl.java:1120)

      at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1073)

      at groovy.lang.ExpandoMetaClass.invokeMethod(ExpandoMetaClass.java:1110)

      at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:901)

      at org.codehaus.groovy.runtime.callsite.PojoMetaClassSite.call(PojoMetaClassSite.java:44)

      at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:112)

      at org.grails.plugin.resource.ResourceTagLib$_writeAttrs_closure11.doCall(ResourceTagLib.groovy:30)

      at sun.reflect.GeneratedMethodAccessor539.invoke(Unknown Source)

      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

      at java.lang.reflect.Method.invoke(Method.java:597)

      at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:90)

      at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:233)

      at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1071)

      at groovy.lang.ExpandoMetaClass.invokeMethod(ExpandoMetaClass.java:1110)

      at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:901)

      at groovy.lang.Closure.call(Closure.java:412)

      at org.codehaus.groovy.runtime.DefaultGroovyMethods.callClosureForMapEntry(DefaultGroovyMethods.java:3591)

      at org.codehaus.groovy.runtime.DefaultGroovyMethods.each(DefaultGroovyMethods.java:1406)

      at org.codehaus.groovy.runtime.dgm$163.invoke(Unknown Source)

      at org.codehaus.groovy.runtime.callsite.PojoMetaMethodSite$PojoMetaMethodSiteNoUnwrapNoCoerce.invoke(

 

 

 

From: Lari Hotari [mailto:[hidden email]]
Sent: 23 April 2012 18:41
To: Gopinath, Dhanush
Cc: [hidden email]
Subject: Re: [grails-user] Thread Blocking at Groovy ExpandoMetaclass method in a Grails App

 


So you are using the "poor man's profiling" method. :) Sometimes it's a nice way to do profiling.

I think you need a real profiler if you want to get more accurate results. For example, it's quite hard to find the "10 top blockers" in your solution without a profiler.

Regards,

Lari

btw. A profiler can also show how many exceptions are created/thrown. Normal execution flow should not throw/catch exceptions since they are relatively heavy weight.



23.04.2012 15:41, Gopinath, Dhanush wrote:

Hi,

 

Unfortunately we do not use Yourkit. We take the JStack output and analyse it in TDA (  Thread Dump Analyser)

 

Dhanush

 

From: Lari Hotari [[hidden email]]
Sent: 23 April 2012 18:05
To: Gopinath, Dhanush
Cc: [hidden email]
Subject: Re: [grails-user] Thread Blocking at Groovy ExpandoMetaclass method in a Grails App

 

Hi,

Is this one a "top blocker" and can you reproduce the performance problem (is it constantly blocking in this method)?

I've been using YourKit Java Profiler for profiling (in sampling mode). To get the "top blockers", I go to "Monitor Usage" tab and sort the results by "count".

I've described my way to profile Grails in this thread: http://grails.1312388.n4.nabble.com/Help-with-a-benchmark-tp3943263p3971929.html . To find out what is blocking, I usually disable all special measurements/probes in YJP (-agentpath:/opt/yjp/bin/linux-x86-32/libyjpagent.so=delay=30000,disableall,sampling,onexit=snapshot) and only enable monitor profiling.

What method are you using to find out what is blocking?


Regards,

Lari



23.04.2012 15:02, Gopinath, Dhanush wrote:

Making the method public also improves the performance, but not sure if this is the correct workaround.

 

I also ran into this issue while we increased the load a bit. TeaContextSport is a class inside a plugin which we are using to access some legacy application, and line no 16 tries to invoke an method in the legacy code. But the thread gets Blocked

 

 

"http-thread-pool-8080(470)" daemon prio=6 tid=0x00000000160d5000 nid=0x19fc waiting for monitor entry [0x000000003ca2b000]

   java.lang.Thread.State: BLOCKED (on object monitor)

        at org.codehaus.groovy.reflection.GeneratedMetaMethod$Proxy.proxy(GeneratedMetaMethod.java:78)

        - waiting to lock <a href="monitor://%3c0x00000007ccaa5790%3e"><0x00000007ccaa5790> (a org.codehaus.groovy.reflection.GeneratedMetaMethod$Proxy)

        at org.codehaus.groovy.reflection.GeneratedMetaMethod$Proxy.doMethodInvoke(GeneratedMetaMethod.java:70)

        at groovy.lang.MetaClassImpl.getProperty(MetaClassImpl.java:1604)

        at groovy.lang.ExpandoMetaClass.getProperty(ExpandoMetaClass.java:1140)

        at groovy.lang.MetaClassImpl.getProperty(MetaClassImpl.java:3332)

        at groovy.lang.ExpandoMetaClass.getProperty(ExpandoMetaClass.java:1152)

        at org.codehaus.groovy.runtime.InvokerHelper.getProperty(InvokerHelper.java:161)

        at org.codehaus.groovy.runtime.callsite.PojoMetaClassGetPropertySite.callGetProperty(PojoMetaClassGetPropertySite.java:41)

        at com.espn.tea.client.TeaContextSport.invokeMethod(TeaContextSport.groovy:16)

        at groovy.lang.GroovyObject$invokeMethod.call(Unknown Source)

        at com.espn.tea.client.TeaContextClient.invokeMethod(TeaContextClient.groovy:28)

        at org.codehaus.groovy.runtime.callsite.PogoMetaClassSite.call(PogoMetaClassSite.java:45)

        at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:116)

        at com.espni.domain.dao.soccer.TeamDao.getTeamById(TeamDao.groovy:61)

        at com.espni.domain.dao.soccer.TeamDao.getTeamById(TeamDao.groovy:55)

        at com.espni.domain.dao.soccer.TeamDao$getTeamById.call(Unknown Source)

        at com.espni.domain.dao.soccer.GameDao.getGame(GameDao.groovy:38)

        at com.espni.domain.dao.soccer.GameDao$getGame.callCurrent(Unknown Source)

        at com.espni.domain.dao.soccer.GameDao.getGameById(GameDao.groovy:94)

        at sun.reflect.GeneratedMethodAccessor1551.invoke(Unknown Source)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

        at java.lang.reflect.Method.invoke(Method.java:597)

        at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:90)

        at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:233)

        at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1071)

        at groovy.lang.ExpandoMetaClass.invokeMethod(ExpandoMetaClass.java:1110)

        at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:901)

        at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1016)

        at groovy.lang.ExpandoMetaClass.invokeMethod(ExpandoMetaClass.java:1110)

        at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:901)

        at org.codehaus.groovy.runtime.callsite.PogoMetaClassSite.callCurrent(PogoMetaClassSite.java:66)

        at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:141)

        at com.espni.domain.dao.soccer.GameDao$_getGamesByLeagueSeason_closure1.doCall(GameDao.groovy:109)

        at sun.reflect.GeneratedMethodAccessor1548.invoke(Unknown Source)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

        at java.lang.reflect.Method.invoke(Method.java:597)

        at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:90)

 

 

 

Reply | Threaded
Open this post in threaded view
|  
Report Content as Inappropriate

Re: Thread Blocking at Groovy ExpandoMetaclass method in a Grails App

Lari Hotari -

Hi,

I have a feeling that ExpandoMetaClass.addSuperMethodIfNotOverridden is not complete ( https://github.com/groovy/groovy-core/blob/GROOVY_1_8_X/src/main/groovy/lang/ExpandoMetaClass.java#L539) . It only handles instances of ClosureMetaMethod.

It seems that performOperationOnMetaClass gets called for each call in some cases.

It would be good if we could isolate this problem so that it can be reported to Groovy Jira .

There might be some workarounds to the problem. I remember examining this particular code ( https://github.com/grails-plugins/grails-resources/blob/master/grails-app/taglib/org/grails/plugin/resource/ResourceTagLib.groovy#L29) that your stack trace contained. I remember doing a small change and that made a big difference. I just couldn't find a good reason why it behaved in that way and didn't investigate the problem further at that time.

Here is an example of a small change I made some time ago to fix one performance problem:
https://github.com/grails/grails-core/commit/62626921ebd80e3cdeb9776fd79be7eb92f88763
In this case PohoMetaMethodSite.checkCall was creating unnecessary ClassCastExceptions that harmed performance. I never reported the problem to Groovy Jira even though that would have been the correct thing to do.

The problem in ResourceTagLib can be somehow similar, so that a small change works around the possible Groovy performance bug.

-

One thing came in to my mind. Usually extreme performance isn't required. You can easily scale a Grails application by putting a caching reverse http proxy in front of the application. Typical solutions are Varnish ( https://www.varnish-cache.org/), Apache mod_proxy&mod_cache , Squid,  etc.
I've written a blog post about using Apache:
http://quest4grail.blogspot.com/2009/08/apache-config-for-aggressive-reverse.html
The Apache mod_proxy/mod_cache solution has some bugs that we've hit:
https://issues.apache.org/bugzilla/show_bug.cgi?id=50024
https://issues.apache.org/bugzilla/show_bug.cgi?id=45868
There is also the cache storm/invalidation problem that has been fixed in Apache 2.2.15 (not available in Ubuntu 10.04 LTS) with the "CacheLock" feature:
http://httpd.apache.org/docs/2.2/mod/mod_cache.html#thunderingherd
(That wasn't available when I wrote the blog article. It's really important for serious installations.)

There are also commercial hardware/software load balancer / caching reverse proxy appliances like Citrix Netscaler, F5 BIG-IP etc.

Usually you have to design the application in a way that it's possible to use the HTTP Cache-Control header to control caching. It's worth separating "public" url space and "private" (after login) url space since the URL is the unique key for HTTP caches. For cacheable urls the URL should always be unique for the content (you have to remove all user personalization and move that information to the url if the url is publicly cacheable). Ajax can be used to load user specific content in this type of caching solution. There must be some good books / references available about this subject.

-

Can you help fixing some of the performance problems by isolating the problems in a simple-as-possible test app with instructions to reproduce the problem? Usually doing that part is half of the solution.


Regards,

Lari




25.04.2012 19:51, Gopinath, Dhanush wrote:

Hi Lari,

 

Now we are consistently getting this exception when we increase the load:

 

"http-thread-pool-8080(350)" daemon prio=6 tid=0x0000000017a20000 nid=0x1518 waiting on condition [0x000000003315b000]

   java.lang.Thread.State: WAITING (parking)

      at sun.misc.Unsafe.park(Native Method)

      - parking to wait for  <0x00000007d100a0f0> (a java.util.concurrent.locks.ReentrantReadWriteLock$NonfairSync)

      at java.util.concurrent.locks.LockSupport.park(LockSupport.java:158)

      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 java.util.concurrent.locks.ReentrantReadWriteLock$WriteLock.lock(ReentrantReadWriteLock.java:807)

      at groovy.lang.ExpandoMetaClass.performOperationOnMetaClass(ExpandoMetaClass.java:809)

      - locked <0x00000007d1009a50> (a groovy.lang.ExpandoMetaClass)

      at groovy.lang.ExpandoMetaClass.addSuperMethodIfNotOverridden(ExpandoMetaClass.java:513)

      at groovy.lang.ExpandoMetaClass.onSuperMethodFoundInHierarchy(ExpandoMetaClass.java:394)

      at groovy.lang.MetaClassImpl.invokeMissingMethod(MetaClassImpl.java:813)

      at groovy.lang.MetaClassImpl.invokePropertyOrMissing(MetaClassImpl.java:1120)

      at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1073)

      at groovy.lang.ExpandoMetaClass.invokeMethod(ExpandoMetaClass.java:1110)

      at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:901)

      at org.codehaus.groovy.runtime.callsite.PojoMetaClassSite.call(PojoMetaClassSite.java:44)

      at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:112)

      at org.grails.plugin.resource.ResourceTagLib$_writeAttrs_closure11.doCall(ResourceTagLib.groovy:30)

      at sun.reflect.GeneratedMethodAccessor539.invoke(Unknown Source)

      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

      at java.lang.reflect.Method.invoke(Method.java:597)

      at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:90)

      at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:233)

      at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1071)

      at groovy.lang.ExpandoMetaClass.invokeMethod(ExpandoMetaClass.java:1110)

      at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:901)

      at groovy.lang.Closure.call(Closure.java:412)

      at org.codehaus.groovy.runtime.DefaultGroovyMethods.callClosureForMapEntry(DefaultGroovyMethods.java:3591)

      at org.codehaus.groovy.runtime.DefaultGroovyMethods.each(DefaultGroovyMethods.java:1406)

      at org.codehaus.groovy.runtime.dgm$163.invoke(Unknown Source)

      at org.codehaus.groovy.runtime.callsite.PojoMetaMethodSite$PojoMetaMethodSiteNoUnwrapNoCoerce.invoke(

 

 

 

From: Lari Hotari [[hidden email]]
Sent: 23 April 2012 18:41
To: Gopinath, Dhanush
Cc: [hidden email]
Subject: Re: [grails-user] Thread Blocking at Groovy ExpandoMetaclass method in a Grails App

 


So you are using the "poor man's profiling" method. :) Sometimes it's a nice way to do profiling.

I think you need a real profiler if you want to get more accurate results. For example, it's quite hard to find the "10 top blockers" in your solution without a profiler.

Regards,

Lari

btw. A profiler can also show how many exceptions are created/thrown. Normal execution flow should not throw/catch exceptions since they are relatively heavy weight.



23.04.2012 15:41, Gopinath, Dhanush wrote:

Hi,

 

Unfortunately we do not use Yourkit. We take the JStack output and analyse it in TDA (  Thread Dump Analyser)

 

Dhanush

 

From: Lari Hotari [[hidden email]]
Sent: 23 April 2012 18:05
To: Gopinath, Dhanush
Cc: [hidden email]
Subject: Re: [grails-user] Thread Blocking at Groovy ExpandoMetaclass method in a Grails App

 

Hi,

Is this one a "top blocker" and can you reproduce the performance problem (is it constantly blocking in this method)?

I've been using YourKit Java Profiler for profiling (in sampling mode). To get the "top blockers", I go to "Monitor Usage" tab and sort the results by "count".

I've described my way to profile Grails in this thread: http://grails.1312388.n4.nabble.com/Help-with-a-benchmark-tp3943263p3971929.html . To find out what is blocking, I usually disable all special measurements/probes in YJP (-agentpath:/opt/yjp/bin/linux-x86-32/libyjpagent.so=delay=30000,disableall,sampling,onexit=snapshot) and only enable monitor profiling.

What method are you using to find out what is blocking?


Regards,

Lari



23.04.2012 15:02, Gopinath, Dhanush wrote:

Making the method public also improves the performance, but not sure if this is the correct workaround.

 

I also ran into this issue while we increased the load a bit. TeaContextSport is a class inside a plugin which we are using to access some legacy application, and line no 16 tries to invoke an method in the legacy code. But the thread gets Blocked

 

 

"http-thread-pool-8080(470)" daemon prio=6 tid=0x00000000160d5000 nid=0x19fc waiting for monitor entry [0x000000003ca2b000]

   java.lang.Thread.State: BLOCKED (on object monitor)

        at org.codehaus.groovy.reflection.GeneratedMetaMethod$Proxy.proxy(GeneratedMetaMethod.java:78)

        - waiting to lock <a moz-do-not-send="true" href="monitor://%3c0x00000007ccaa5790%3e"><0x00000007ccaa5790> (a org.codehaus.groovy.reflection.GeneratedMetaMethod$Proxy)

        at org.codehaus.groovy.reflection.GeneratedMetaMethod$Proxy.doMethodInvoke(GeneratedMetaMethod.java:70)

        at groovy.lang.MetaClassImpl.getProperty(MetaClassImpl.java:1604)

        at groovy.lang.ExpandoMetaClass.getProperty(ExpandoMetaClass.java:1140)

        at groovy.lang.MetaClassImpl.getProperty(MetaClassImpl.java:3332)

        at groovy.lang.ExpandoMetaClass.getProperty(ExpandoMetaClass.java:1152)

        at org.codehaus.groovy.runtime.InvokerHelper.getProperty(InvokerHelper.java:161)

        at org.codehaus.groovy.runtime.callsite.PojoMetaClassGetPropertySite.callGetProperty(PojoMetaClassGetPropertySite.java:41)

        at com.espn.tea.client.TeaContextSport.invokeMethod(TeaContextSport.groovy:16)

        at groovy.lang.GroovyObject$invokeMethod.call(Unknown Source)

        at com.espn.tea.client.TeaContextClient.invokeMethod(TeaContextClient.groovy:28)

        at org.codehaus.groovy.runtime.callsite.PogoMetaClassSite.call(PogoMetaClassSite.java:45)

        at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:116)

        at com.espni.domain.dao.soccer.TeamDao.getTeamById(TeamDao.groovy:61)

        at com.espni.domain.dao.soccer.TeamDao.getTeamById(TeamDao.groovy:55)

        at com.espni.domain.dao.soccer.TeamDao$getTeamById.call(Unknown Source)

        at com.espni.domain.dao.soccer.GameDao.getGame(GameDao.groovy:38)

        at com.espni.domain.dao.soccer.GameDao$getGame.callCurrent(Unknown Source)

        at com.espni.domain.dao.soccer.GameDao.getGameById(GameDao.groovy:94)

        at sun.reflect.GeneratedMethodAccessor1551.invoke(Unknown Source)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

        at java.lang.reflect.Method.invoke(Method.java:597)

        at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:90)

        at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:233)

        at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1071)

        at groovy.lang.ExpandoMetaClass.invokeMethod(ExpandoMetaClass.java:1110)

        at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:901)

        at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1016)

        at groovy.lang.ExpandoMetaClass.invokeMethod(ExpandoMetaClass.java:1110)

        at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:901)

        at org.codehaus.groovy.runtime.callsite.PogoMetaClassSite.callCurrent(PogoMetaClassSite.java:66)

        at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:141)

        at com.espni.domain.dao.soccer.GameDao$_getGamesByLeagueSeason_closure1.doCall(GameDao.groovy:109)

        at sun.reflect.GeneratedMethodAccessor1548.invoke(Unknown Source)

        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

        at java.lang.reflect.Method.invoke(Method.java:597)

        at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:90)

 

 

 


12
Loading...