Wiki source code of Debugging

Last modified by Thomas Mortagne on 2020/03/10 09:54

Show last authors
1 There are several possibilities for debugging XWiki:
2
3 {{toc/}}
4
5 = Debug mode =
6
7 [Since 7.1]
8
9 It's possible to enable debug log by adding ##debug=true## (as in [[http://127.0.0.1:8080/xwiki/bin/Main/WebHome?debug=true]]) to the URL. This provide various details on what exactly happens during the request.
10
11 == Elapsed time tree ==
12
13 A detailed tree of how long has been spent in each step. You can add you own step to the tree by using [[progress API>>extensions:Extension.Job Module||anchor="HNotifyaboutprogress"]].
14
15 {{image reference="elapsedtimetree.png"/}}
16
17 = Debugging XWiki from your IDE =
18
19 == Debugging with Eclipse ==
20
21 Once you've gotten the debugger working, you'll wonder how you ever survived without it.
22
23 === Complete tutorial based on M2E and WTP ===
24
25 [[Debug XWiki with Eclipse>>DebugXEWithEclipse]]
26
27 === Debug a XWiki released version ===
28
29 * Follow the steps from [[Building In Eclipse>>BuildingInEclipse]] including the optional "Import the WAR as a web project".
30 * Select from the Eclipse menu **Run > Debug...**
31 * Create a new configuration for your server
32 * Hit the **Debug** button
33 * Set breakpoints, step through code, have fun!
34
35 WTP will deploy XWiki into ##{workspace_location}/.metadata/.plugins/org.eclipse.wst.server.core/tmp0/webapps/xwiki##. If you suspect a change has not been deployed correctly (e.g. a change to a config file), check there to confirm.
36
37 If you are working on an XWiki plugin in a separate project in your workspace, you can ensure it is automatically deployed to XWiki's ##WEB-INF/lib## directory when debugging. Open the project properties of the XWiki project resulting from the WAR import above, go to the ##J2EE Module Dependencies## section, and add your plugin project.
38
39 === Using Firebug when debugging a selenium test ===
40
41 For that you will need to install Firebug [[as a global extension>>http://kb.mozillazine.org/Installing_extensions#Global_installation]]
42
43 = Remote Debugging =
44
45 To perform remote debugging, start your wiki in debug mode. To do this modify the way you start your container and ensure that the following JVM parameters are passed:
46
47 {{code}}
48 -Xdebug -Xnoagent -Djava.compiler=NONE -Xrunjdwp:transport=dt_socket,server=y,suspend=n,address=5005
49 {{/code}}
50
51 For example, for Jetty you could use the following start script:
52
53 {{code}}
54 #!/bin/sh
55
56 JETTY_HOME=.
57 JETTY_PORT=8080
58 JAVA_OPTS="-Xmx300m -Xdebug -Xnoagent -Djava.compiler=NONE -Xrunjdwp:transport=dt_socket,server=y,suspend=n,address=5005"
59
60 java $JAVA_OPTS -Dfile.encoding=iso-8859-1 -Djetty.port=$JETTY_PORT -Djetty.home=$JETTY_HOME -jar $JETTY_HOME/start.jar
61 {{/code}}
62
63 {{info}}
64 You can also easily run Jetty in debug mode by using the [[jettyrun profile in the Maven build>>Building#HUsingProfiles]].
65 {{/info}}
66
67 If you are using the Tomcat service on Windows, you should modify the JVM args with the Tomcat Service Configuration Panel. Select the Java tab and add each of the options **on a separate line**. For example:
68
69 {{code}}
70 -Dcatalina.home=C:\Program Files\Apache Software Foundation\Tomcat 5.5
71 -Dcatalina.base=C:\Program Files\Apache Software Foundation\Tomcat 5.5
72 -Djava.endorsed.dirs=C:\Program Files\Apache Software Foundation\Tomcat 5.5\common\endorsed
73 -Djava.io.tmpdir=C:\Program Files\Apache Software Foundation\Tomcat 5.5\temp
74 -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager
75 -Djava.util.logging.config.file=C:\Program Files\Apache Software Foundation\Tomcat 5.5\conf\logging.properties
76 -Xdebug
77 -Xnoagent
78 -Djava.compiler=NONE
79 -Xrunjdwp:transport=dt_socket,address=8000,server=y,suspend=n
80 {{/code}}
81
82 Then, in your favorite IDE, open the XWiki project and run a remote debugging session, attached to the socket on port 5005. For example, if you're using IntelliJ IDEA, go to ##Run|Edit Configurations...## and create a new ##Remote## configuration (default parameters should be fine). Then execute it and IDEA will connect to the executing JVM.
83
84 You can then place breakpoints in your source code.
85
86 = Logging =
87
88 == Turning on logging inside XWiki ==
89
90 See the [[Logging page in the Admin guide>>platform:AdminGuide.Logging]].
91
92 == Logging shutdown operations ==
93
94 {{info}}XWiki 6.3M1+{{/info}} To log debug information of what happens when there are shutdown operations, simply set the log level to ##DEBUG## for the ##org.xwiki.shutdown## logger:
95
96 {{code language="xml"}}
97 <logger name="org.xwiki.shutdown" level="info"/>
98 {{/code}}
99
100 == Logging calls at the database level ==
101
102 You have several options:
103
104 * Configure Hibernate to log SQL calls. To do this edit XWiki's log configuration file (see the [[Logging page>>platform:AdminGuide.Logging]]) and change the log level from ##warn## to ##trace## for the following:(((
105 {{code language="none"}}
106 <!-- Log HQL query parser activity -->
107 <logger name="org.hibernate.hql.ast.AST" level="warn"/>
108 <!-- Log just the SQL -->
109 <logger name="org.hibernate.SQL" level="warn"/>
110 <!-- Log JDBC bind parameters -->
111 <logger name="org.hibernate.type" level="warn"/>
112 <!-- Log schema export/update -->
113 <logger name="org.hibernate.tool.hbm2ddl" level="warn"/>
114 <!-- Log HQL parse trees -->
115 <logger name="org.hibernate.hql" level="warn"/>
116 <!-- Log cache activity -->
117 <logger name="org.hibernate.cache" level="warn"/>
118 <!-- Log transaction activity -->
119 <logger name="org.hibernate.transaction" level="warn"/>
120 <!-- Log JDBC resource acquisition -->
121 <logger name="org.hibernate.jdbc" level="warn"/>
122 <!-- Enable the following line if you want to track down connection leakages when using
123 DriverManagerConnectionProvider -->
124 <logger name="org.hibernate.connection.DriverManagerConnectionProvider" level="warn"/>
125 <!-- Log prepared statement cache activity -->
126 <logger name="org.hibernate.ps.PreparedStatementCache" level="warn"/>
127 {{/code}}
128 )))
129 * Use a wrapping JDBC driver such as [[log4jdbc>>http://code.google.com/p/log4jdbc/]] or [[p6spy>>http://sourceforge.net/projects/p6spy/]].
130 * (((
131 Turn on logging in your database. The configuration is database-dependent* (((
132 For **HSQLDB**. Two solutions:* Solution 1: Edit ##WEB-INF/hibernate.cfg.xml## and modify the URL connection property to add ##hsqldb.sqllog=3##, as in:(((
133 {{code language="none"}}
134 <property name="connection.url">jdbc:hsqldb:file:${environment.permanentDirectory}/database/xwiki_db;shutdown=true;hsqldb.sqllog=3</property>
135 {{/code}}
136 )))
137 * Solution 2: Using Byteman (See the section below for more information). For example the following rule (tested on HSQLDB 2.3.1) will log SQL statements with parameters and schema when there's more than 1 parameter:(((
138 {{code language="none"}}
139 RULE Log SQL Statement
140 CLASS org.hsqldb.Session
141 METHOD executeCompiledStatement(org.hsqldb.Statement, Object[], int)
142 AT ENTRY
143 IF $2.length > 0
144 DO traceln("SQL Statement = [" + $1.getSQL() + "], parameter 1 = [" + $2[0] + "], schema = [" + $1.getSchemaName().name + "]")
145 ENDRULE
146 {{/code}}
147
148 Will give for example:
149
150 {{code language="none"}}
151 SQL Statement = [select xwikidocum0_.XWD_ID as XWD1_0_0_, xwikidocum0_.XWD_FULLNAME as XWD2_0_0_, xwikidocum0_.XWD_NAME as XWD3_0_0_, xwikidocum0_.XWD_TITLE as XWD4_0_0_, xwikidocum0_.XWD_LANGUAGE as XWD5_0_0_, xwikidocum0_.XWD_DEFAULT_LANGUAGE as XWD6_0_0_, xwikidocum0_.XWD_TRANSLATION as XWD7_0_0_, xwikidocum0_.XWD_DATE as XWD8_0_0_, xwikidocum0_.XWD_CONTENT_UPDATE_DATE as XWD9_0_0_, xwikidocum0_.XWD_CREATION_DATE as XWD10_0_0_, xwikidocum0_.XWD_AUTHOR as XWD11_0_0_, xwikidocum0_.XWD_CONTENT_AUTHOR as XWD12_0_0_, xwikidocum0_.XWD_CREATOR as XWD13_0_0_, xwikidocum0_.XWD_WEB as XWD14_0_0_, xwikidocum0_.XWD_CONTENT as XWD15_0_0_, xwikidocum0_.XWD_VERSION as XWD16_0_0_, xwikidocum0_.XWD_CUSTOM_CLASS as XWD17_0_0_, xwikidocum0_.XWD_PARENT as XWD18_0_0_, xwikidocum0_.XWD_CLASS_XML as XWD19_0_0_, xwikidocum0_.XWD_ELEMENTS as XWD20_0_0_, xwikidocum0_.XWD_DEFAULT_TEMPLATE as XWD21_0_0_, xwikidocum0_.XWD_VALIDATION_SCRIPT as XWD22_0_0_, xwikidocum0_.XWD_COMMENT as XWD23_0_0_, xwikidocum0_.XWD_MINOREDIT as XWD24_0_0_, xwikidocum0_.XWD_SYNTAX_ID as XWD25_0_0_, xwikidocum0_.XWD_HIDDEN as XWD26_0_0_ from xwikidoc xwikidocum0_ where xwikidocum0_.XWD_ID=?], parameter 1 = [-4526159677276379501], schema = [TEST91]
152 {{/code}}
153 )))
154 )))
155 )))
156
157 == Logging HTTP calls ==
158
159 XWiki uses [[HTTP Client>>https://hc.apache.org/httpcomponents-client-ga/]] in most places and logging what it does is easy. You'll need to add the following to XWiki's ##logback.xml## file:
160
161 {{code language="xml"}}
162 <logger name="org.apache.http" level="debug"/>
163 <logger name="org.apache.http.headers" level="debug"/>
164 <logger name="org.apache.http.wire" level="debug"/>
165 {{/code}}
166
167 == Using Byteman ==
168
169 [[Byteman>>https://www.jboss.org/byteman]] is a great framework that allows to modify bytecode in a running JVM. It can easily be used to add logging (for ex) to find out what's happening in a running XWiki instance. Here's a quick tutorial:
170
171 * Download Byteman and unzip it in a directory. Set the ##$BYTEMAN_HOME## environment property to point to the directory where you've unzipped it. For example:
172 {{code}}export BYTEMAN_HOME=/Users/vmassol/dev/byteman/byteman-download-2.1.0{{/code}}
173 * Start an XWiki instance somewhere on the same machine
174 * Go to ##$BYTEMAN_HOME/bin## and connect Byteman to XWiki. For example:
175 {{code}}sh bminstall.sh -b -Dorg.jboss.byteman.transform.all jetty/start.jar{{/code}}
176 * Now create a Byteman rule by creating a file, for example ##my.btm## with the following:(((
177 {{code}}
178 RULE XWiki Docs loaded
179 CLASS XWikiHibernateStore
180 METHOD loadXWikiDoc
181 AT ENTRY
182 IF TRUE
183 DO traceln("Load document = " + $1.getDocumentReference())
184 ENDRULE
185 {{/code}}
186 )))
187 * Load this rule with: {{code}}sh bmsubmit.sh -l my.btm{{/code}}
188 * Call a URL in your wiki and check that the console prints the document references that get loaded! For example:(((
189 {{code}}
190 Load document = xwiki:Main.WebPreferences
191 Load document = xwiki:ColorThemes.DefaultColorTheme
192 Load document = xwiki:XWiki.SearchSuggestConfig
193 Load document = xwiki:XWiki.SearchSuggestConfig
194 Load document = xwiki:Dashboard.WebHome
195 Load document = xwiki:XWiki.GadgetClass
196 Load document = xwiki:Dashboard.WebHome
197 Load document = xwiki:Dashboard.WebPreferences
198 Load document = xwiki:Dashboard.colibri
199 Load document = xwiki:Main.Welcome
200 ...
201 {{/code}}
202 )))
203 * Modify your rule or add new rules to the same file and apply the changes with {{code}}sh bmsubmit.sh -l my.btm{{/code}}
204 * Remove your rules with {{code}}sh bmsubmit.sh -u{{/code}}
205
206 For more read [[A Byteman tutorial>>https://community.jboss.org/wiki/ABytemanTutorial]] or the [[Reference documentation>>http://downloads.jboss.org/byteman/2.0.1/ProgrammersGuideSinglePage.html]].
207
208 === Examples ===
209
210 ==== Example 1 ====
211
212 In this example we'll print calls to ##CommonsConfigurationSource.containsKey(...)## with the parameters printed and the time it takes to execute. In addition we'll also print calls to ##XWiki.getDocument(String, XWikiContext)## which is a deprecated method which, for the purpose of this example, we think generate the calls to ##containsKey##.
213
214 {{code}}
215 RULE Create timer for containsKey
216 CLASS CommonsConfigurationSource
217 METHOD containsKey
218 AT ENTRY
219 IF TRUE
220 DO resetTimer("containsKey")
221 ENDRULE
222
223 RULE Calls to containsKey
224 CLASS CommonsConfigurationSource
225 METHOD containsKey
226 AT EXIT
227 IF TRUE
228 DO traceln("containsKey for [" + $1 + "] = [" + $! + "], time = [" + getElapsedTimeFromTimer("containsKey") + "]")
229 ENDRULE
230
231 RULE Calls to deprecated getDocument
232 CLASS com.xpn.xwiki.XWiki
233 METHOD getDocument(String, XWikiContext)
234 AT ENTRY
235 IF TRUE
236 DO traceStack("getDocument() called for [" + $1 + "] ", 3)
237 ENDRULE
238 {{/code}}
239
240 Generates:
241
242 {{code}}
243 ...
244 getDocument() called for [XWiki.Admin] com.xpn.xwiki.XWiki.getDocument(XWiki.java:-1)
245 com.xpn.xwiki.XWiki.getUserName(XWiki.java:5072)
246 com.xpn.xwiki.XWiki.getUserName(XWiki.java:5062)
247 . . .
248 containsKey for [model.reference.default.document] = [false], time = [0]
249 containsKey for [model.reference.default.document] = [false], time = [0]
250 containsKey for [model.reference.default.space] = [false], time = [0]
251 containsKey for [model.reference.default.space] = [false], time = [0]
252 containsKey for [model.reference.default.wiki] = [false], time = [0]
253 containsKey for [model.reference.default.wiki] = [false], time = [1]
254 getDocument() called for [XWiki.DefaultSkin] com.xpn.xwiki.XWiki.getDocument(XWiki.java:-1)
255 com.xpn.xwiki.XWiki.getSkinFile(XWiki.java:1955)
256 com.xpn.xwiki.XWiki.getSkinFile(XWiki.java:1918)
257 . . .
258 ...
259 {{/code}}
260
261 ==== Example 2 ====
262
263 Log calls to ##XWikiDocument#setLock()## and ##XWikiDocument#removeLock()##.
264
265 {{code}}
266 RULE XWiki Set Lock
267 CLASS XWikiDocument
268 METHOD setLock
269 AT ENTRY
270 IF TRUE
271 DO traceln("set lock for user [" + $1 + "], doc = [" + $this + "]")
272 ENDRULE
273
274 RULE XWiki Remove Lock
275 CLASS XWikiDocument
276 METHOD removeLock
277 AT ENTRY
278 IF TRUE
279 DO traceln("remove lock for doc = [" + $this + "]")
280 ENDRULE
281
282 RULE XWiki Get Lock
283 CLASS XWikiDocument
284 METHOD getLock
285 AT ENTRY
286 IF TRUE
287 DO traceln("get lock for doc = [" + $this + "]")
288 ENDRULE
289 {{/code}}
290
291 When you click edit and then cancel on a doc you get for example:
292
293 {{code}}
294 // Edit
295 get lock for doc = [Sandbox.WebHome]
296 set lock for user [XWiki.Admin], doc = [Sandbox.WebHome]
297 get lock for doc = [Sandbox.WebHome]
298 get lock for doc = [Sandbox.WebHome]
299 set lock for user [XWiki.Admin], doc = [Sandbox.WebHome]
300
301 // Cancel
302 get lock for doc = [Sandbox.WebHome]
303 remove lock for doc = [Sandbox.WebHome]
304 {{/code}}
305
306 When you click edit and then save on a doc you get for example:
307
308 {{code}}
309 // Edit
310 get lock for doc = [Sandbox.WebHome]
311 set lock for user [XWiki.Admin], doc = [Sandbox.WebHome]
312 get lock for doc = [Sandbox.WebHome]
313 get lock for doc = [Sandbox.WebHome]
314 set lock for user [XWiki.Admin], doc = [Sandbox.WebHome]
315
316 // Save
317 get lock for doc = [Sandbox.WebHome]
318 remove lock for doc = [Sandbox.WebHome]
319 get lock for doc = [Sandbox.WebHome]
320 {{/code}}
321
322 === Troubleshooting ===
323
324 ==== NoClassDefFoundError: com/sun/tools/attach/AttachNotSupportedException ====
325
326 If you get the following exception, it can mean that you're on Mac and that your ##tools.jar## is not added to the classpath. Apparently ##bminstall.sh## thinks that if you're on Mac then you don't need ##tools.jar## which is apparently wrong nowadays.
327
328 {{code language="none"}}
329 Exception in thread "main" java.lang.NoClassDefFoundError: com/sun/tools/attach/AttachNotSupportedException
330 at java.lang.Class.getDeclaredMethods0(Native Method)
331 at java.lang.Class.privateGetDeclaredMethods(Class.java:2701)
332 at java.lang.Class.privateGetMethodRecursive(Class.java:3048)
333 at java.lang.Class.getMethod0(Class.java:3018)
334 at java.lang.Class.getMethod(Class.java:1784)
335 at sun.launcher.LauncherHelper.validateMainClass(LauncherHelper.java:544)
336 at sun.launcher.LauncherHelper.checkAndLoadMain(LauncherHelper.java:526)
337 Caused by: java.lang.ClassNotFoundException: com.sun.tools.attach.AttachNotSupportedException
338 at java.net.URLClassLoader.findClass(URLClassLoader.java:382)
339 at java.lang.ClassLoader.loadClass(ClassLoader.java:424)
340 at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:349)
341 at java.lang.ClassLoader.loadClass(ClassLoader.java:357)
342 ... 7 more
343 {{/code}}
344
345 In this case, edit ##bminstall.sh## and add the following line below the ##OS=`uname`## line in order to override it:
346
347 {{code language="none"}}
348 OS=whatever
349 {{/code}}
350
351 = Debugging JavaScript =
352
353 The solution is to use a Browser add-on for inspecting JavaScript and putting breakpoints in it. The issue is that by default the XWiki build will minify and aggregate JavaScript files for performance reasons.
354
355 However there's a solution:
356
357 * Start by building XWiki with the ##debug## profile (##mvn clean install -Pdebug##)
358 * Then once you're on a page make sure to pass ##?minify=false## in the URL. If you don't do this then the aggregated JS files are going to be referenced and since they don't exist, the JS code will break. Since 7.1 you can instead set ##debug.minify## to ##false## in ##xwiki.properties## file.
359
360 = Debugging the WYSIWYG editor =
361
362 Example to debug JS code in ##macroSelector.js##:
363
364 * Modify the top level CKEditor ##pom.xml## to remove minification (the important part is {{code}}--leave-js-unminified{{/code}}):(((
365 {{code language="xml"}}
366 ...
367 <plugin>
368 <groupId>org.codehaus.mojo</groupId>
369 <artifactId>exec-maven-plugin</artifactId>
370 <executions>
371 <!-- Build the CKEditor. -->
372 <execution>
373 <id>build-ckeditor</id>
374 <!-- Use a phase after compile because the Clirr Maven Plugin executes all the phases up to compile twice. -->
375 <phase>process-classes</phase>
376 <goals>
377 <goal>exec</goal>
378 </goals>
379 <configuration>
380 <executable>${ckeditor.builder.path}/build.sh</executable>
381 <arguments>
382 <argument>-s --leave-js-unminified</argument>
383 </arguments>
384 </configuration>
385 </execution>
386 </executions>
387 </plugin>
388 ...
389 {{/code}}
390 )))
391 * Rebuild the ##application-ckeditor-webjar## module (you'll also need to rebuild##application-ckeditor-plugins## if you made changes to it).
392 * Copy the generated ##application-ckeditor-webjar-<version>.jar## to an XWiki instance, in ##WEB-INF/lib## and restart XWiki
393 * In the wiki, edit ##CKEditor.EditSheet## in object mode and look for ###set ($macroWizardBundlePath = "${ckeditorBasePath}plugins/xwiki-macro/macroWizard.bundle.min")## and remove the ##.min## part. Note that in this case you have to know that the macro wizard is loaded separately in ##macroWizard.bundle.min.js##. Otherwise the JS is in ##ckeditor.js##.
394 * Use your browser's dev tools to put breakpoints in the JS.
395
396 = Analyze Out Of Memory issues =
397
398 You can enable automatic memory dump when using ##-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/where/to/save/the/memory/dumps ## which will generate a memory dump as soon as Java detect an Out Of memory error. See https://docs.oracle.com/javase/8/docs/technotes/guides/troubleshoot/clopts001.html#CHDFDIJI for more details.
399
400 Since 7.2RC1 the option is enabled by default in Jetty based distributions and the memory dump will ends up in ##data/## folder.

Get Connected