Profiling
Profiling is useful to find out performance bottlenecks and find out memory hogs. There are 2 types of tools that can be easily used to profile XWiki.Profiling using a Profiler
The best tool for the job is of course a profiler. Follow the steps:- Get a profiler
- Build XWiki or simply download a XWiki binary release
- Check your profiler's documentation to see the command line that needs to be added when starting the XWiki JVM. For example for YourKit, add the following to the xwiki_start_debug.sh script and replace with the location of YourKit on your system (these commands are actually already there so you can simply uncomment them):
JAVA_OPTS="$JAVA_OPTS -agentlib:yjpagent" export 'DYLD_LIBRARY_PATH=/Applications/YourKit Java Profiler 6.0.15.app/bin/mac'
- Run the Profile and then start XWiki
Profiling using XWiki's Debugging Aspect
This is a poor man's profiler but it's very easy to use and useful in some cases where using a proper profiler is not an option (like when you have a novice user having a problem you cannot reproduce on your machine and you need to get information from running XWiki on his machine). Follow these steps:- Build XWiki using the debug profile. For example for XE, run mvn clean install -Pdebug,xe from the top level. This will make the xwiki-core module apply an AspectJ aspect to the whole core code. This Aspect logs all methods calls.
- Before you run the generated distribution, you'll want to create a log4j.properties file in WEB-INF/classes so that it overrides the default one in XWiki's JAR and so that you tell the AspectJ aspect to only log some portion of the code. If you don't do that you'll get overwhelmed by all the logging and performances will drop severely. For example, to only log methods in XWikiAction and in the renderer classes, you'd write something like:
### Direct log messages to stdout
log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.Target=System.out
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern=%d{ABSOLUTE} [%t] %-5p %-30.30c{2} %x - %m %n
log4j.appender.file=org.apache.log4j.RollingFileAppender
log4j.appender.file.File=xwiki.log
log4j.appender.file.MaxFileSize=10MB
log4j.appender.file.MaxBackupIndex=50
log4j.appender.file.layout=org.apache.log4j.PatternLayout
log4j.appender.file.layout.ConversionPattern=%d{ABSOLUTE} [%t] %-5p %-30.30c{2} %x - %m %n
### By default everything that is of warning or severity WARN, ERROR or FATAL is logged both to
### the console and to the xwiki.log file.
log4j.rootLogger=warn, stdout, file
### Hibernate logging options
log4j.logger.org.hibernate=warn
log4j.logger.org.hibernate.SQL=warn
log4j.logger.org.hibernate.type=warn
log4j.logger.org.hibernate.ps.PreparedStatementCache=warn
### XWiki logging configuration
log4j.logger.com.xpn.xwiki=warn
log4j.logger.com.xpn.xwiki.render.XWikiRadeoxRenderEngine=warn
### Deactive Radeox warnings
log4j.logger.org.radeox.macro.BaseLocaleMacro=error
### Deactive Struts warnings
log4j.logger.org.apache.struts.util.RequestUtils=error
### Deactivate JGroups warnings
log4j.logger.org.jgroups=error
## Deactive PDF Export CSS Applier warnings
log4j.logger.info.informatica.doc.style.css.dom=error
log4j.logger.org.apache.fop.layoutmgr.inline.ContentLayoutManager=error
## Log only some classes in the AspectJ aspect
log4j.logger.com.xpn.xwiki.XWikiAction=debug
log4j.logger.com.xpn.xwiki.render.DefaultXWikiRenderingEngine=debug
log4j.logger.com.xpn.xwiki.render.XWikiRadeoxRenderer=debug
log4j.logger.com.xpn.xwiki.render.XWikiWikiBaseRenderer=debug
log4j.logger.com.xpn.xwiki.render.XWikiVelocityRenderer=debug
log4j.logger.com.xpn.xwiki.render.XWikiMacrosMappingRenderer=debug- Then you need to configure the AspectJ aspect. This is done by passing system properties to the JVM that starts XWiki. If you're using the provided start_xwiki.sh script, modify it such as follows:
... java %JAVA_OPTS% -Ddebug.active=true -Ddebug.minTime=100 -Ddebug.showDetails=false -Dfile.encoding=iso-8859-1 -Djetty.home=%JETTY_HOME% -Djetty.port=%JETTY_PORT% -jar %JETTY_HOME%/start.jar
- debug.active: Whether debugging is on or not. By default it's false and no logging is done by the AspectJ aspect
- debug.minTime: Only logs methods that take longer than this value. Defaults to 100ms.
- debug.showDetails: If true then logs parameter values and method return values. Defaults is false.
14:27:10,685 [P1-16] DEBUG render.XWikiVelocityRenderer - 386 evaluate 14:27:10,685 [P1-16] DEBUG render.XWikiVelocityRenderer - 386 evaluate 14:27:10,948 [P1-16] DEBUG render.XWikiVelocityRenderer - 411 evaluate 14:27:10,948 [P1-16] DEBUG render.XWikiVelocityRenderer - 411 evaluate 14:27:11,116 [P1-16] DEBUG render.XWikiVelocityRenderer - 348 evaluate 14:27:11,116 [P1-16] DEBUG render.XWikiVelocityRenderer - 348 evaluate 14:27:11,631 [P1-16] DEBUG render.XWikiVelocityRenderer - 694 evaluate 14:27:11,631 [P1-16] DEBUG render.XWikiVelocityRenderer - 694 evaluate 14:27:11,631 [P1-16] DEBUG render.XWikiVelocityRenderer - 1337 evaluate 14:27:11,631 [P1-16] DEBUG render.XWikiVelocityRenderer - 1337 evaluate 14:27:11,801 [P1-16] DEBUG render.XWikiRadeoxRenderer - 307 render 14:27:11,808 [P1-16] DEBUG er.DefaultXWikiRenderingEngine - 356 renderText 14:27:11,808 [P1-16] DEBUG er.DefaultXWikiRenderingEngine - 356 renderText 14:27:11,809 [P1-16] DEBUG er.DefaultXWikiRenderingEngine - 357 renderDocument 14:27:11,857 [P1-16] DEBUG render.XWikiVelocityRenderer - 406 evaluate 14:27:11,857 [P1-16] DEBUG render.XWikiVelocityRenderer - 406 evaluate 14:27:12,035 [P1-16] DEBUG render.XWikiVelocityRenderer - 359 evaluate 14:27:12,036 [P1-16] DEBUG render.XWikiVelocityRenderer - 360 evaluate 14:27:12,154 [P1-16] DEBUG er.DefaultXWikiRenderingEngine - 286 renderText 14:27:12,154 [P1-16] DEBUG er.DefaultXWikiRenderingEngine - 286 renderText 14:27:12,416 [P1-16] DEBUG render.XWikiRadeoxRenderer - 352 render 14:27:12,425 [P1-16] DEBUG er.DefaultXWikiRenderingEngine - 449 renderText 14:27:12,426 [P1-16] DEBUG er.DefaultXWikiRenderingEngine - 450 renderText 14:27:12,654 [P1-16] DEBUG render.XWikiVelocityRenderer - 393 evaluate 14:27:12,654 [P1-16] DEBUG render.XWikiVelocityRenderer - 393 evaluate 14:27:12,655 [P1-16] DEBUG render.XWikiVelocityRenderer - 393 render 14:27:12,698 [P1-16] DEBUG er.DefaultXWikiRenderingEngine - 452 renderText 14:27:12,698 [P1-16] DEBUG er.DefaultXWikiRenderingEngine - 452 renderText 14:27:12,805 [P1-16] DEBUG render.XWikiVelocityRenderer - 944 evaluate 14:27:12,805 [P1-16] DEBUG render.XWikiVelocityRenderer - 944 evaluate 14:27:12,866 [P1-16] DEBUG render.XWikiVelocityRenderer - 1011 evaluate 14:27:12,866 [P1-16] DEBUG render.XWikiVelocityRenderer - 1011 evaluate 14:27:12,866 [P1-16] DEBUG render.XWikiVelocityRenderer - 2579 evaluate 14:27:12,867 [P1-16] DEBUG render.XWikiVelocityRenderer - 2580 evaluate 14:27:13,651 [P1-16] DEBUG er.DefaultXWikiRenderingEngine - 318 interpretText 14:27:13,885 [P1-16] DEBUG er.DefaultXWikiRenderingEngine - 287 interpretText 14:27:14,051 [P1-17] DEBUG er.DefaultXWikiRenderingEngine - 302 interpretText 14:27:14,392 [P1-16] DEBUG er.DefaultXWikiRenderingEngine - 342 interpretText
Version 1.1 last modified by VincentMassol on 30/08/2007 at 13:53
Document data
Attachments:
No attachments for this document
Comments: 0