On Feb 8, 2013, at 9:46 AM, Vincent Massol <[email protected]> wrote:
> > On Feb 8, 2013, at 12:35 AM, Ludovic Dubost <[email protected]> wrote: > >> Hi, >> >> I've been testing newrelic which has some interesting live JVM analysis. >> I've been running the JVM Profiling while running a load test going on >> various XWiki pages (except activity stream) including AWM, LiveTable >> Searches, Content pages, Lucene search and loading ressources. >> >> Here is a result of the profiling: >> >> 25.0% - java.net.SocketInputStream.socketRead0 >> 32 Collapsed methods (show) >> 25.0% - com.xpn.xwiki.store.hibernate.query.HqlQueryExecutor.execute >> 21.0% - org.xwiki.query.internal.DefaultQueryExecutorManager.execute >> 11.0% - org.xwiki.query.internal.DefaultQuery.execute >> 127 Collapsed methods (show) >> 11.0% - java.lang.Thread.run >> 9.9% - org.xwiki.query.internal.SecureQueryExecutorManager.execute >> 4.2% - com.xpn.xwiki.store.hibernate.query.DefaultQueryExecutor.execute >> 12.0% - org.apache.velocity.runtime.parser.node.SimpleNode.render >> 12.0% - org.xwiki.velocity.internal.DefaultVelocityEngine.evaluate >> 12.0% - org.xwiki.velocity.internal.DefaultVelocityEngine.evaluate >> 8.1% - >> org.xwiki.rendering.internal.macro.velocity.VelocityMacro.evaluateString >> 4.3% - com.xpn.xwiki.render.XWikiVelocityRenderer.evaluate >> 9.2% - org.xwiki.velocity.internal.DefaultVelocityEngine.evaluate >> 8.5% - com.xpn.xwiki.render.DefaultVelocityManager.getVelocityEngine >> 4.1% - org.apache.velocity.runtime.parser.node.ASTBlock.render >> 4.1% - com.xpn.xwiki.web.XWikiAction.execute >> 3.6% - >> org.xwiki.rendering.internal.transformation.macro.MacroTransformation.transformOnce >> 3.2% - org.apache.velocity.runtime.directive.Foreach.render >> 2.9% - >> org.xwiki.rendering.wikimodel.xwiki.xwiki21.javacc.XWikiScanner.docElements >> 2.8% - com.xpn.xwiki.plugin.lucene.SearchResults.getRelevantResults >> 2.6% - com.xpn.xwiki.render.XWikiVelocityRenderer.evaluate >> 2.4% - com.mysql.jdbc.PreparedStatement.executeQuery >> 2.4% - org.xwiki.uiextension.internal.WikiUIExtension.getParameters >> 2.3% - org.xwiki.rendering.wikimodel.xwiki.xwiki21.javacc.XWikiScanner.line >> >> My understanding is that we spend 25% of time reading from the DB (this >> could be livetable related for instance). Around 50 in various velocity >> parts. Around 10% in the XWiki rendering and 3% in Lucene search. 2,4% in >> UI extensions (no visible rights, probably because running as Admin) >> >> Velocity is clearly quite expensive. Now I see particularly: >> >> 8.5% - com.xpn.xwiki.render.DefaultVelocityManager.getVelocityEngine >> >> Would this mean we are spending 8,5% of the time getting the velocity >> engine to use ? > > Yes, I had already noticed that. There's a synchronization done on that > method that is probably costly. I'll look into it. I've created and implemented http://jira.xwiki.org/browse/XWIKI-8801 Would be great if you could retest with it. Thanks -Vincent > Thanks > -Vincent > >> This sounds a lot. >> >> In any case this is food for thoughts for future optimizations. >> >> Ludovic _______________________________________________ devs mailing list [email protected] http://lists.xwiki.org/mailman/listinfo/devs
