users@glassfish.java.net

Re: Extremely slow startup - JVMStatsProviderBootstrap the culprit?

From: Byron Nevins <byron.nevins_at_oracle.com>
Date: Wed, 27 Apr 2011 10:32:12 -0700

I filed a high-priority bug:

http://java.net/jira/browse/GLASSFISH-16478


On 4/27/2011 2:44 AM, forums_at_java.net wrote:
> Hi
>
> This is with Glassfish 3.1.
>
> We are trying to track down an issue where our Glassfish startup has
> become
> occasionally (but not consistently) painfully slow along with very
> high CPU
> (over 100% of 1 CPU) usage for the Glassfish process. Slow here means
> many
> minutes for loading a particular webapp, as opposed to 1-2 minutes.
>
> Checking GC with VisualVM showed no problems - enough heap, infrequent
> collections - and the VE itself was not swapping.
>
> On running several stack trace dumps back to back I found that the main
> thread was spending a lot of time in this section of code (across several
> stack trace dumps) - In particular, I was seeing the thread remain in the
> string pattern matching section started by
> org.glassfish.flashlight.datatree.impl.AbstractTreeNode.getNodesInternal(AbstractTreeNode.java:360).
>
>
> "main" prio=10 tid=0x000000004efe1000 nid=0x163e runnable
> [0x000000004092e000] java.lang.Thread.State: RUNNABLE at
> java.lang.String.length(String.java:651) at
> java.util.regex.Matcher.getTextLength(Matcher.java:1140) at
> java.util.regex.Matcher.reset(Matcher.java:291) at
> java.util.regex.Matcher.<init>(Matcher.java:211) at
> java.util.regex.Pattern.matcher(Pattern.java:888) at
> org.glassfish.flashlight.datatree.impl.AbstractTreeNode.getNodesInternal(AbstractTreeNode.java:360)
>
> at
> org.glassfish.flashlight.datatree.impl.AbstractTreeNode.getNodes(AbstractTreeNode.java:331)
>
> at
> org.glassfish.admin.monitor.StatsProviderManagerDelegateImpl.resetChildNodeStatistics(StatsProviderManagerDelegateImpl.java:550)
>
> at
> org.glassfish.admin.monitor.StatsProviderManagerDelegateImpl.resetStatistics(StatsProviderManagerDelegateImpl.java:539)
>
> at
> org.glassfish.admin.monitor.StatsProviderManagerDelegateImpl.enableStatsProvider(StatsProviderManagerDelegateImpl.java:389)
>
> at
> org.glassfish.admin.monitor.StatsProviderManagerDelegateImpl.tryToRegister(StatsProviderManagerDelegateImpl.java:191)
>
> at
> org.glassfish.admin.monitor.StatsProviderManagerDelegateImpl.register(StatsProviderManagerDelegateImpl.java:157)
>
> at
> org.glassfish.external.probe.provider.StatsProviderManager.registerStatsProvider(StatsProviderManager.java:91)
>
> at
> org.glassfish.external.probe.provider.StatsProviderManager.register(StatsProviderManager.java:82)
>
> at
> org.glassfish.external.probe.provider.StatsProviderManager.register(StatsProviderManager.java:72)
>
> at
> org.glassfish.admin.monitor.jvm.JVMStatsProviderBootstrap.postConstruct(JVMStatsProviderBootstrap.java:92)
>
> at
> com.sun.hk2.component.AbstractCreatorImpl.inject(AbstractCreatorImpl.java:131)
>
> at
> com.sun.hk2.component.ConstructorCreator$1.run(ConstructorCreator.java:86)
> at java.security.AccessController.doPrivileged(Native Method) at
> com.sun.hk2.component.ConstructorCreator.initialize(ConstructorCreator.java:83)
>
> at
> com.sun.hk2.component.AbstractCreatorImpl.get(AbstractCreatorImpl.java:82)
> at
> com.sun.hk2.component.SingletonInhabitant.get(SingletonInhabitant.java:67)
> - locked <0x00002aab01bcf370> (a
> com.sun.hk2.component.SingletonInhabitant)
> at
> com.sun.hk2.component.EventPublishingInhabitant.get(EventPublishingInhabitant.java:139)
>
> at
> com.sun.hk2.component.AbstractInhabitantImpl.get(AbstractInhabitantImpl.java:76)
>
> at
> com.sun.enterprise.v3.server.AppServerStartup.run(AppServerStartup.java:326)
>
> at
> com.sun.enterprise.v3.server.AppServerStartup.start(AppServerStartup.java:135)
>
> - locked <0x00002aaac20b3228> (a
> com.sun.enterprise.v3.server.AppServerStartup) at
> com.sun.enterprise.glassfish.bootstrap.GlassFishImpl.start(GlassFishImpl.java:79)
>
> - locked <0x00002aaac20b3200> (a
> com.sun.enterprise.glassfish.bootstrap.GlassFishImpl) at
> com.sun.enterprise.glassfish.bootstrap.GlassFishMain$Launcher.launch(GlassFishMain.java:117)
>
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at
> sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
>
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>
> at java.lang.reflect.Method.invoke(Method.java:597) at
> com.sun.enterprise.glassfish.bootstrap.GlassFishMain.main(GlassFishMain.java:97)
>
> at com.sun.enterprise.glassfish.bootstrap.ASMain.main(ASMain.java:55)
> I don't know if this is a red herring, but nothing else in the stack
> traces
> stood out as much as this did.
>
> Any tips?
>
> Thanks
>
> Patrick
>
>
>
>
> --
>
> [Message sent by forum member 'pdoubleya']
>
> View Post: http://forums.java.net/node/795868
>
>

-- 
Oracle <http://www.oracle.com>
Byron Nevins | Principal MTS
Phone: +1 6503958992 <tel:+1%206503958992>
Green Oracle <http://www.oracle.com/commitment> Oracle is committed to 
developing practices and products that help protect the environment