Search performance comparison for %SEARCH% and FormQueryPlugin

I have done some timing comparison between searches using %SEARCH% and searches using FormQueryPlugin, for your entertainment.

The timing was done using ab in the following manner:

ab -n 5 -c 1 http://hostname/path

The web searched contains 2085 topics, 1949 of which are of the form ComponentEntry.* and represent a data base implemented in TWiki.

The searches apply a criteria to retrieve a set of topics and extract several formfields and render them in a table.

Summary

The mean time obtained over serveral test runs were:

As you can see, there is potentially a significant advantage of using FormQueryPlugin.

However, there is also a downside: The timing of FormQueryPlugin assumed an up-to-date cache. If the cache has to be reconstructed during the search, this will take an average of 26077 ms in the example web, thus tripling the search time. Aggressive cache management (e.g., regularly updating the cache via a cron job) will help avoid unexpected slow queries.

Simple criteria

%SEARCH%

| * * | *Asset* | *Component* | *KLOC* | *Status* | *Reusable* | *Manager* |
%SEARCH{ "[C]lassification.*value\=\\"Devices\\";[S]ub-classification.*value\=\\"Browser\\"" casesensitive="on" regex="on" nosearch="on" nototal="on" format="| [[$topic][<img src=\"%PUBURLPATH%/%TWIKIWEB%/TWikiDocGraphics/edittopic.gif\" border=\"0\" alt=\"View entry\" />]] | $formfield(Assetname) | $formfield(Componentname) |$formfield(KLOC) | $formfield(Status) | $formfield(Reusable) | $formfield(Manager) |"}%

Result:

Connnection Times (ms)
              min  mean[+/-sd] median   max
Connect:        2     3    1.7      2     6
Processing:  9625  9914  201.3   9936 10188
Waiting:     9621  9911  200.9   9933 10186
Total:       9625  9917  202.6   9938 10194

FormQueryPlugin

| * * | *Asset* | *Component* | *KLOC* | *Status* | *Reusable* | *Manager* |
%FORMQUERY{ name="q1" search="Classification='Devices' AND Subclassification='Browser'" casesensitive="on" }%
| * * | *Asset* | *Component* | *KLOC* | *Status* | *Reusable* | *Manager* |
%SHOWQUERY{ query="q1" format="| [[$topic][<img src=\"%PUBURLPATH%/%TWIKIWEB%/TWikiDocGraphics/edittopic.gif\" border=\"0\" alt=\"View entry\" />]] | $Assetname | $Componentname | $KLOC | $Status | $Reusable | $Manager |"}%

Result:

Connnection Times (ms)
              min  mean[+/-sd] median   max
Connect:        2     4    3.9      3    12
Processing:  8488  8832  241.7   8895  9137
Waiting:     8485  8830  242.2   8893  9136
Total:       8488  8836  242.8   8902  9139

Complex criteria

%SEARCH%

<form action="%SCRIPTURLPATH%/view%SCRIPTSUFFIX%/%WEB%/%TOPIC%"> 
|*View, edit:*|*Classification*|*Sub-classification*|*Asset*|*Component*|*KLOC*|*Status*|*Reusable*|
|*<input type="submit" value="Filter" />*|*<input type="text" name="qClass" size="20" value="%URLPARAM{"qClass"}" />*|*<input type="text" name="qSub" value="%URLPARAM{"qSub"}%" size="20" />*|*<input type="text" name="qAss" value="%URLPARAM{"qAss"}%" size="20" />*|*<input type="text" name="qComp" value="%URLPARAM{"qComp"}%" size="30" />*|*&nbsp;*|*<select name="qStatus" size="1"> <option>%URLPARAM{"qStatus"}%</option> <option></option> <option>In Process</option> <option>Active</option> <option>Archived</option> <option>Obsolete</option> </select>*|*<select name="qReuse" size="1"> <option>%URLPARAM{"qReuse"}%</option> <option></option> <option>Yes</option> <option>No</option> </select>*|
%SEARCH{ search="META:FIELD.*?\\"Classification.*?%URLPARAM{"qClass"}%;META:FIELD.*?Subclassification\\".*?%URLPARAM{"qSub"}%;META:FIELD.*?Assetname.*?%URLPARAM{"qAss"}%;META:FIELD.*?Componentname.*?%URLPARAM{"qComp"}%;META:FIELD.*?Status.*?%URLPARAM{"qStatus"}%;META:FIELD.*?Reusable.*?%URLPARAM{"qReuse"}%;META:FIELD.*?Productline.*?%URLPARAM{"productline"}%" topic="ComponentEntry*"  nosearch="on" nototal="on" regex="on" noheader="on" terminator="on" format="| [[$web.$topic][<img src=\"%PUBURLPATH%/%TWIKIWEB%/TWikiDocGraphics/viewtopic.gif\" border=\"0\" alt=\"View entry\" />]] [[%SCRIPTURL%/edit%SCRIPTSUFFIX%/$web/$topic?t=%GMTIME{"$hour$min$sec"}%][<img src=\"%PUBURLPATH%/%TWIKIWEB%/TWikiDocGraphics/edittopic.gif\" border=\"0\" alt=\"Edit entry\" />]] | $formfield(Classification) | $formfield(Subclassification) | $formfield(Assetname) | $formfield(Componentname) |$formfield(KLOC) | $formfield(Status) | $formfield(Reusable) |" }%

Result:

Connnection Times (ms)
              min  mean[+/-sd] median   max
Connect:        2     4    2.5      4     9
Processing: 25141 26856 1955.9  27414 29158
Waiting:    25137 26854 1955.7  27413 29155
Total:      25141 26860 1954.8  27420 29161

FormQueryPlugin

<form action="%SCRIPTURLPATH%/view%SCRIPTSUFFIX%/%WEB%/%TOPIC%"> 
%FORMQUERY{name="plsearch" search="topic='ComponentEntry.*' AND Productline='%URLPARAM{"productline"}%' AND Classification='%URLPARAM{"qClass"}%' AND Subclassification=~'%URLPARAM{"qSub"}%' AND Assetname=~'%URLPARAM{"qAss"}%' AND Componentname=~'%URLPARAM{"qComp"}%' AND Status='%URLPARAM{"qStatus"}%' AND Reusable='%URLPARAM{"qReuse"}%'"}%
|*View, edit:*|*Classification*|*Sub-classification*|*Deliverable*|*Component*|*KLOC*|*Status*|*Reusable*|
|*<input type="submit" value="Filter" />*|*<input type="text" name="qClass" size="20" value="%URLPARAM{"qClass"}" />*|*<input type="text" name="qSub" value="%URLPARAM{"qSub"}%" size="20" />*|*<input type="text" name="qAss" value="%URLPARAM{"qAss"}%" size="20" />*|*<input type="text" name="qComp" value="%URLPARAM{"qComp"}%" size="30" />*|*&nbsp;*|*<select name="qStatus" size="1"> <option>%URLPARAM{"qStatus"}%</option> <option></option> <option>In Process</option> <option>Active</option> <option>Archived</option> <option>Obsolete</option> </select>*|*<select name="qReuse" size="1"> <option>%URLPARAM{"qReuse"}%</option> <option></option> <option>Yes</option> <option>No</option> </select>*|
%SHOWQUERY{query="plsearch" terminator="on" format="| [[$web.$topic][<img src=\"%PUBURLPATH%/%TWIKIWEB%/TWikiDocGraphics/viewtopic.gif\" border=\"0\" alt=\"View entry\" />]] [[%SCRIPTURL%/edit%SCRIPTSUFFIX%/$web/$topic?t=%GMTIME{"$hour$min$sec"}%][<img src=\"%PUBURLPATH%/%TWIKIWEB%/TWikiDocGraphics/edittopic.gif\" border=\"0\" alt=\"Edit entry\" />]] | $Classification | $Subclassification | $Assetname | $Componentname |$KLOC | $Status | $Reusable |" }%

Result:

Connnection Times (ms)
              min  mean[+/-sd] median   max
Connect:        2     3    1.7      3     7
Processing:  9151  9636  464.1   9593 10392
Waiting:     9148  9634  463.8   9590 10390
Total:       9151  9639  466.2   9596 10399

-- ThomasWeigert - 28 Jul 2005