Performance test on Jetty/HSQLDB with a single wiki between $doc.getValue('previous') and $doc.getValue('next')

Version 212.1 by Thomas Mortagne on 2017/01/11 18:06
Warning: For security reasons, the document is displayed in restricted mode as it is not the current version. There may be differences and errors due to this.

Environment

Failed to execute the [velocity] macro. Cause: [The execution of the [velocity] script macro is not allowed in [test:Performances.Jetty HSQLDB single wiki 844 to 92]. Check the rights of its last author or the parameters if it's rendered from another script.]. Click on this message for details.

  • Ubuntu 16.10 64b
  • Quad core i7-6700HQ
  • Oracle JDK 1.8.0_111 64b
  • Dumbbench 0.10
  • standard jetty+hsqldb
  • permdir in a SSD
  • 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 Dumbbench

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:

wget --save-cookies cookies.txt --post-data 'j_username=Admin&j_password=admin&j_rememberme=true' -O /dev/null -o /dev/null "http://127.0.0.1:8080/xwiki/bin/loginsubmit/XWiki/XWikiLogin?j_username=Admin&j_password=admin&j_rememberme=true"

Tests

Summary

Jetty start takes longer because of:

  • Let's Encrypt registration (which recreate the certificate store). This module is not embedded anymore in 9.0.
  • Full loading of core extensions. The size of the wiki has no impact on time spent (the number of core extension did not changed) but has a huge impact on memory used (since it applies to all extension, not only core extensions).

The skin is a lot slower than in 7.4.2.

A lot of work has been done to improve Solr UI display (reduced a bit by the time spent displaying the skin).

The memory has been reduced a lot compared to 8.3 thanks to optimization in the way to create Extension instances to reduce a lot the duplications (only one instances kept for same Version, ExtensionDependency, etc.). The difference is even more important in very big wikis like http://myxwiki.org which contains a huge number of installed extensions cached in memory.

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

Note that most of the speed related values are an average of very moving results, a lot of things is 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 startup+25%
First accessnot existing page without UIsimilar
not existing page with UI+36%
Reloadnot existing page without UIsimilar
not existing page with UI+35%
empty page without UIsimilar
empty page with UI+22%
Main.WebHome without UI/5
Main.WebHome with UI-21%
SOLRFull SOLR reindexsimilar
SOLR sync when index is emptysimilar
SOLR sync when there is nothing to dosimilar
Result of search finding lots of results-23%
Result of search finding one result-32%
RenderingPage with 1000 macros without UI-15%
Page with 1000 html macros without UI-17%

Memory

ActionsDifference
Heap Memory after jetty startupsimilar
Heap Memory after full SOLR indexused a lot more but keep the same memory

Jetty startup

Unit: seconds

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

  • 7.4.5: 8
  • 8.4.4: 10

First access

First HTTP request after restarting Jetty.

First access to not existing page without UI

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

Unit: seconds

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

  • 7.4.5: 5
  • 8.4.4: 5

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).

  • 7.4.5: 11
  • 8.4.4: 15

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 -p 0.1 -i 1000 -- wget -q -o /dev/null -O /dev/null --load-cookies cookies.txt "http://127.0.0.1:8080/xwiki/bin/get/NoSpace/NoPage"

Unit: milliseconds

  • 7.4.5: 6.5
  • 8.4.4: 6.2

Reload of not existing page with UI

dumbbench -p 0.1 -i 1000 -- wget -q -o /dev/null -O /dev/null --load-cookies cookies.txt "http://127.0.0.1:8080/xwiki/bin/view/NoSpace/NoPage"

Unit: milliseconds

  • 7.4.5: 60
  • 8.4.4: 81

Reload of empty page without UI

dumbbench -p 0.1 -i 1000 -- wget -q -o /dev/null -O /dev/null --load-cookies cookies.txt "http://127.0.0.1:8080/xwiki/bin/get/EmptySpace/EmptyPage"

Unit: milliseconds

  • 7.4.5: 6.5
  • 8.4.4: 6.4

Reload of empty page with UI

dumbbench -p 0.1 -i 1000 -- wget -q -o /dev/null -O /dev/null --load-cookies cookies.txt "http://127.0.0.1:8080/xwiki/bin/view/EmptySpace/EmptyPage"

Unit: milliseconds

  • 7.4.5: 65
  • 8.4.4: 79

Reload of Main.WebHome without UI

dumbbench -p 0.1 -i 1000 -- wget -q -o /dev/null -O /dev/null --load-cookies cookies.txt "http://127.0.0.1:8080/xwiki/bin/get/Main/WebHome"

Unit: milliseconds

  • 7.4.5: 44
  • 8.4.4: 8

Reload of Main.WebHome with UI

dumbbench -p 0.1 -i 1000 -- wget -q -o /dev/null -O /dev/null --load-cookies cookies.txt "http://127.0.0.1:8080/xwiki/bin/view/Main/WebHome"

Unit: milliseconds

  • 7.4.5: 107
  • 8.4.4: 85

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 Yourkit (Yourkit is slowing down a bit all that but what is important is the difference anyway).

  • 7.4.5: 50
  • 8.4.4: 55

SOLR sync

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

when index is empty

Unit: seconds

  • 7.4.5: < 1
  • 8.4.4: < 1

when there is nothing to do

Unit: seconds

  • 7.4.5: < 1
  • 8.4.4: < 1

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 -p 0.1 -i 100 -- wget -q -o /dev/null -O /dev/null --load-cookies cookies.txt "http://127.0.0.1:8080/xwiki/bin/view/Main/Search?sort=score&sortOrder=desc&r=1&f_type=DOCUMENT&text=*"
  • 7.4.5: 198
  • 8.4.4: 153

Result of search finding one result

dumbbench -p 0.1 -i 100 -- wget -q -o /dev/null -O /dev/null --load-cookies cookies.txt "http://127.0.0.1:8080/xwiki/bin/view/Main/Search?sort=score&sortOrder=desc&r=1&f_type=DOCUMENT&text=name%3A1000Macros"
  • 7.4.5: 165
  • 8.4.4: 113

Rendering

Page with 1000 macros without UI

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

Unit: milliseconds

  • 7.4.5: 75
  • 8.4.4: 64

Page with 1000 html macros without UI

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

Unit: milliseconds

  • 7.4.5: 774
  • 8.4.4: 645

Heap Memory

Attach Yourkit 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 the values.

  • 7.4.5: 41 used, 480 allocated
  • 8.4.4: 46 used, 556 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 the values.

Unit: MB

  • 7.4.5: 160 used, 505 allocated
  • 8.4.4: 159 used, 807 allocated

Get Connected