Search query awful performances
Hi
I'm experiencing a big performance problem on query performance on a CQ 5.4 instance.
Some info:
CQ 5.4 - all hotfixes applied
repository.xml and workspace.xml optimizations done (index cache set to 150000), bundle cache size to 1024 Mb... even indexInMemory set to true (is it doing something really good?)
Memory: 10 Gb
Repository: approx 500.000 pages ... some millions of nodes
Workspace: approx 30Gb... Lucene index folder: approx 30Gb Datastore: approx 500 Gb
Restarting CQ, no editors working on it, going in site admin and simply making a search with the simple 'searchfield' placed on the top right corner.
This is the equivalent query reported in error.log:
ROOT=group: limit=6, excerpt=true, offset=0[
{group=group: or=true[
{0_fulltext=fulltext: relPath=jcr:content, fulltext=auto*}
{1_fulltext=fulltext: relPath=jcr:content/@jcr:title, fulltext=auto*}
{2_fulltext=fulltext: relPath=jcr:content/@jcr:description, fulltext=auto*}
]}
{path=path: path=/content}
{type=type: type=nt:hierarchyNode}
{orderByScore=orderby: sort=desc, orderby=@jcr:score}
]
Time required to complete... incredibly long.... about 15 minutes... here follows time spent from error.log.
19.12.2013 20:30:15.538 *INFO* [10.46.128.3 [1387480183910] GET /content.search.json HTTP/1.1] com.day.cq.search.impl.builder.QueryImpl xpath query took 1231613 ms
19.12.2013 20:30:15.538 *INFO* [10.46.128.3 [1387480183910] GET /content.search.json HTTP/1.1] com.day.cq.search.impl.builder.QueryImpl >> xpath query returned 46263 results
19.12.2013 20:30:15.538 *INFO* [10.46.128.3 [1387480183910] GET /content.search.json HTTP/1.1] com.day.cq.search.impl.builder.QueryImpl entire query execution took 1231613 ms
19.12.2013 20:30:15.538 *INFO* [10.46.128.3 [1387480486038] GET /content.search.json HTTP/1.1] com.day.cq.search.impl.builder.QueryImpl xpath query took 929500 ms
19.12.2013 20:30:15.538 *INFO* [10.46.128.3 [1387480486038] GET /content.search.json HTTP/1.1] com.day.cq.search.impl.builder.QueryImpl >> xpath query returned 46263 results
19.12.2013 20:30:15.538 *INFO* [10.46.128.3 [1387480486038] GET /content.search.json HTTP/1.1] com.day.cq.search.impl.builder.QueryImpl entire query execution took 929500 ms
During query execution I analyzed disk resources with a performance monitor. I'm attaching the screen capture. Many lucene index files opened and a lot of I/O activity.
I'm really concerned about this situation. After first execution caches are populated and other queries will progressively take less time... they start to be 'normal'. But as soon as caches are discarded, bad performances come back.
This situation is creating a lot of problems to editorial activity and also to search functionalities on publish site.
I understand that JCR does not have direct support for ordering... so the OOTB query done by CQ in this case is really heavy... but... hey... we cannot think to make queries without ordering results :)
The same situation with a SQL Query on a database would be completed in few seconds, not minutes. So I would like to think that there is some I/O problem that is forcing a query to last 15 minutes instead of 5 seconds as it should be at max.
Any help will be really appreciated.