Performance test on Jetty/HSQLDB with a single wiki between 12.10.11 and 13.10.2

Last modified by Ilie Andriuta on 2022/02/14 15:24

Environment

  • Windows 11 64bit version 21H2
  • Quad core i7-9750H
  • Oracle JDK 17.0.1 (build 17.0.1+12-LTS-39)
  • Dumbbench 0.501
  • VisualVM 2.1.1
  • standard jetty+hsqldb
  • permdir in a SSD
  • jetty/hsqldb package
  • only main wiki
  • configuration
    • Admin user:
      • hidden documents enabled
  • import perf.xar

Most of response time statistics are made with Dumbbench, you can install it using cpan.
For example on Debian/Ubuntu:

$ sudo apt-get install cpanminus
$ sudo cpanm Module::Install
$ sudo cpanm Dumbbench

On Windows 11:

  1. Install perl from https://strawberryperl.com/
  2. Go to Windows Terminal and install Dumbbench:
    PS C:\> perl
    PS C:\> cpanm Dumbbench
  3. (If needed) Download wget.exe (64 bit) from https://eternallybored.org/misc/wget/

    Make a folder for testing the instances and put wget.exe there.

Unless specifically indicated otherwise all the tests are executed with a fully initialized instance (core extensions don't run anymore, SOLR index is fully up to date, etc.) and logged in with Admin user. Basically except for a few special tests we are using an instance that already been started and run until the proc is flat for some time.

Login with Admin user (using port 1115):

.\wget.exe --save-cookies cookies.txt --post-data 'j_username=Admin&j_password=admin&j_rememberme=true' "http://127.0.0.1:1115/xwiki/bin/loginsubmit/XWiki/XWikiLogin?j_username=Admin&j_password=admin&j_rememberme=true"

Tests

Summary

"similar": difference is lower than 10%
"slightly": difference is lower than 20%

Information

Note that most of the speed related values are an average of very fast moving results, a lot of things are happening during a HTTP request and it's far from stable duration (that's why 10% may sounds a lot for something called "similar" but the variable can go up and down around 5% sometimes so 10% average is really not that much of a clear win). Dumbbench based tests are executed several times and the lowest result is selected.

Speed

ActionsDifference
Jetty startupsimilar
First accessnot existing page without UIsimilar
not existing page with UIsimilar
Reloadnot existing page without UI-25%
not existing page with UIsimilar
empty page without UIslightly slower
empty page with UI+23%
Main.WebHome without UI+72%
Main.WebHome with UI+36%
SOLRFull SOLR reindexsimilar
SOLR sync when index is emptysimilar
SOLR sync when there is nothing to do+30%
Result of search finding lots of resultsslightly slower
Result of search finding one result+33%
RenderingPage with 1000 macros without UIslightly slower
Page with 1000 html macros without UIx11
Wiki creationFrom flavorsimilar
From templatesimilar

Memory

ActionsDifference
Heap Memory after jetty startup-3 MB
Heap Memory after full SOLR index-21 MB

Jetty startup

Unit: milliseconds

You get this from the log with the line looking like 2016-10-19 16:52:25.309:INFO:oejs.Server:main: Started @8434ms.

  • 12.10.11: 13227
  • 13.10.2: 12691

First access

First HTTP request after restarting Jetty.

First access to not existing page without UI

(/xwiki/bin/get/NoSpace/NoPage)

Unit: milliseconds

Firefox network statistics to load the root resource (image/js/css/etc. resources are not taken into account).

  • 12.10.11: 9880
  • 13.10.2: 9185

First access to not existing page with UI

(/xwiki/bin/view/NoSpace/NoPage)

Unit: seconds

Done by hand with a chronometer (image/js/css/etc. resources are not taken into account).

  • 12.10.11: 17
  • 13.10.2: 17

Reload

XWiki is doing nothing on background and everything is both in server and client cache already. Values are calculated using dumbbench (image/js/css/etc. resources are not taken into account).

Reload of not existing page without UI

dumbbench --float -p 0.1 -i 100 -- wget -q -o NUL -O NUL --load-cookies cookies.txt "http://127.0.0.1:1115/xwiki/bin/get/NoSpace/NoPage"

Unit: milliseconds

  • 12.10.11: 4
  • 13.10.2: 3

Reload of not existing page with UI

dumbbench --float -p 0.1 -i 100 -- wget -q -o NUL -O NUL --load-cookies cookies.txt "http://127.0.0.1:1115/xwiki/bin/view/NoSpace/NoPage"

Unit: milliseconds

  • 12.10.11: 22.9
  • 13.10.2: 24.9

Reload of empty page without UI

dumbbench --float -p 0.1 -i 100 -- wget -q -o NUL -O NUL --load-cookies cookies.txt "http://127.0.0.1:1115/xwiki/bin/get/EmptySpace/EmptyPage"

Unit: milliseconds

  • 12.10.11: 1.9
  • 13.10.2: 2.3

Reload of empty page with UI

dumbbench --float -p 0.1 -i 100 -- wget -q -o NUL -O NUL --load-cookies cookies.txt "http://127.0.0.1:1115/xwiki/bin/view/EmptySpace/EmptyPage"

Unit: milliseconds

  • 12.10.11: 20.9
  • 13.10.2: 29.4

Results of tests for 13.10.2:

Test 1: 0.302130 (30.2 ms)
Test 2: 0.298200 (29.8 ms)
Test 3: 0.301270 (30.1 ms)
Test 4: 0.299440 (29.9 ms)
Test 5: 0.294460 (29.4 ms)

Reload of Main.WebHome without UI

dumbbench --float -p 0.1 -i 100 -- wget -q -o NUL -O NUL --load-cookies cookies.txt "http://127.0.0.1:1115/xwiki/bin/get/Main/WebHome"

Unit: milliseconds

  • 12.10.11: 2.2
  • 13.10.2: 3.8

Results of tests for 13.10.2:

Test 1: 0.040570 (4 ms)
Test 2: 0.040030 (4 ms)
Test 3: 0.039820 (3.9 ms)
Test 4: 0.038890 (3.9 ms)
Test 5: 0.038340 (3.8 ms)

Reload of Main.WebHome with UI

dumbbench --float -p 0.1 -i 100 -- wget -q -o NUL -O NUL --load-cookies cookies.txt "http://127.0.0.1:1115/xwiki/bin/view/Main/WebHome"

Unit: milliseconds

  • 12.10.11: 22.0
  • 13.10.2: 29.9

Results of tests for 13.10.2:

Test 1: 0.313980 (31.4 ms)
Test 2: 0.312300 (31.2 ms)
Test 3: 0.311090 (31.1 ms)
Test 4: 0.299490 (29.9 ms)
Test 5: 0.311400 (31.1 ms)

SOLR

Full SOLR reindex

Unit: seconds

Delete the data/solr folder, restart, load home page and calculate the time of activity of the SOLR index thread using VisualVM (XWiki Solr index thread from Threads Tab > Running column, after it's parked).

  • 12.10.11: 118
  • 13.10.2: 120

SOLR sync

Only the thread determining what need to be indexed and not the actual indexing.

<perm dir>/data/jobs/status/solr/indexer/status.xml

when index is empty

Unit: nanoseconds

  • 12.10.11: 779798800 (779 ms)
  • 13.10.2: 821758900 (821 ms)

when there is nothing to do

Unit: nanoseconds

  • 12.10.11: 297154110 (297 ms)
  • 13.10.2: 386884000 (387 ms)

Results of tests for 13.10.2:

Test 1: 483042900 (483 ms)
Test 2: 440044200 (440 ms)
Test 3: 386884000 (387 ms)
Test 4: 433155700 (433 ms)
Test 5: 471937299 (472 ms)

Search

XWiki is doing nothing on background and everything is both in server and client cache already. Values are calculated using dumbbench (image/js/css/etc. resources are not taken into account).

Unit: milliseconds

Result of search finding lots of results

Login with Admin user and make sure hidden document display is enabled.

dumbbench --float -p 0.1 -i 100 -- wget -q -o NUL -O NUL --load-cookies cookies.txt """http://127.0.0.1:1115/xwiki/bin/view/Main/Search?sort=score&sortOrder=desc&r=1&f_type=DOCUMENT&text=*"""
  • 12.10.11: 42
  • 13.10.2: 51

Result of search finding one result

dumbbench --float -p 0.1 -i 100 -- wget -q -o NUL -O NUL --load-cookies cookies.txt """http://127.0.0.1:1115/xwiki/bin/view/Main/Search?sort=score&sortOrder=desc&r=1&f_type=DOCUMENT&text=name%3A1000Macros"""
  • 12.10.11: 29
  • 13.10.2: 40

Results of tests for 13.10.2:

Test 1: 0.417900 (42 ms)
Test 2: 0.422500 (42 ms)
Test 3: 0.424200 (42 ms)
Test 4: 0.420170 (42 ms)
Test 5: 0.405200 (40 ms)

Rendering

Page with 1000 macros without UI

dumbbench --float -p 0.1 -i 100 -- wget -q -o NUL -O NUL --load-cookies cookies.txt "http://127.0.0.1:1115/xwiki/bin/get/Test/1000Macros"

Unit: milliseconds

  • 12.10.11: 7
  • 13.10.2: 81

Results of tests for 13.10.2:

Test 1: 0.822600 (82 ms)
Test 2: 0.824600 (82 ms)
Test 3: 0.835300 (84 ms)
Test 4: 0.841600 (84 ms)
Test 5: 0.813700 (81 ms)

Page with 1000 html macros without UI

dumbbench --float -p 0.1 -i 100 -- wget -q -o NUL -O NUL --load-cookies cookies.txt "http://127.0.0.1:1115/xwiki/bin/get/Test/1000HTMLMacros"

Unit: milliseconds

  • 12.10.11: 54
  • 13.10.2: 103

Results of tests for 13.10.2:

Test 1: 1.034800 (103 ms)
Test 2: 1.041500 (104 ms)
Test 3: 1.067300 (107 ms)
Test 4: 1.040300 (104 ms)
Test 5: 1.041900 (104 ms)

Wiki creation

Unit: nanoseconds

From flavor

Create the wiki test1 from default flavor and get the time spent from the job (</rootStep> in <permdir>/jobs/status/wikicreation/createandinstall/test1/status.xml).

  • 12.10.11: 24216814700 (24.2 s)
  • 13.10.2: 24512078400 (24.5 s)

From template

Make test1 a template wiki.

Create the wiki test2 from wiki test1 and get the time spend from the job (</rootStep> in <permdir>/jobs/status/wikicreation/createandinstall/test2/status.xml).

  • 12.10.11: 25164017200 (25.2 s)
  • 13.10.2: 26161395300 (26.2 s)

Heap Memory

Attach VisualVM to get the information.

Unit: MB

Heap Memory after jetty startup

Start jetty and wait until Java is not doing anything on both (wait for potential initialization of various stuff like core extension cache, etc). Force garbage collector before looking at "used".

  • 12.10.11: 90 used, 279 allocated
  • 13.10.2: 87 used, 213 allocated

Heap Memory after full SOLR index

Delete the data/solr folder, restart, load home page then wait until nothing is happening in background. Force garbage collector before looking at "used".

Unit: MB

  • 12.10.11: 257 used, 874 allocated
  • 13.10.2: 236 used, 804 allocated

Get Connected