Re: [xwiki-devs] Testing some JVM Analysis Tool

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 ?

This sounds a lot. In any case this is food for thoughts for future optimizations. Ludovic