I wonder why the following facet calculation takes so slow:
FOR q IN LRQ
COLLECT profile = q.LongRunningQuery.Profile INTO profiles
RETURN { "Profile" : profile, "Count" : LENGTH(profiles)}
It takes about 30 seconds, although only 5.000 documents are in the db, and only 30 different facets are in the result.
The field LongRunningQuery.Profile is indexed with a hash index, and with a skiplist index. (I also tried with different combinations of them).
Has anybody a hint for me what might go wrong? Is it possible that the queries do not benefit from the indexes? (the 5.000 records are about 1 GB of size, so I assume the hash index will not be used, maybe a fulltable scan instead?)
Interestingly, the following alternative only lasts 2 seconds:
FOR q IN SKIPLIST(LRQ, { "LongRunningQuery.Profile": [ [ '>', '' ] ] })[*].LongRunningQuery.Profile
COLLECT profile = q INTO profiles
RETURN { "Profile" : profile, "Count" : LENGTH(profiles) }
But it still needs 2 seconds - for such a small amount of records. Here it looks like the skiplist index is used, but it is maybe not the perfect index variant.
Update 2014-11-27:
arangosh [_system]> stmt._query
FOR q IN LRQ COLLECT profile = q.LongRunningQuery.Profile INTO profiles RETURN {
"Profile" : profile, "Count" : LENGTH(profiles)}
arangosh [_system]> db.LRQ.ensureHashIndex("LongRunningQuery.Profile");
{
"id" : "LRQ/296017913256",
"type" : "hash",
"unique" : false,
"fields" : [
"LongRunningQuery.Profile"
],
"isNewlyCreated" : false,
"error" : false,
"code" : 200
}
The query took about 32 seconds and returned 31 short results.
Execution plan:
{
"plan": {
"nodes": [
{
"type": "SingletonNode",
"dependencies": [],
"id": 1,
"estimatedCost": 1,
"estimatedNrItems": 1
},
{
"type": "EnumerateCollectionNode",
"dependencies": [
1
],
"id": 2,
"estimatedCost": 5311,
"estimatedNrItems": 5310,
"database": "_system",
"collection": "LRQ",
"outVariable": {
"id": 0,
"name": "q"
}
},
{
"type": "CalculationNode",
"dependencies": [
2
],
"id": 3,
"estimatedCost": 10621,
"estimatedNrItems": 5310,
"expression": {
"type": "attribute access",
"name": "Profile",
"subNodes": [
{
"type": "attribute access",
"name": "LongRunningQuery",
"subNodes": [
{
"type": "reference",
"name": "q",
"id": 0
}
]
}
]
},
"outVariable": {
"id": 3,
"name": "3"
},
"canThrow": false
},
{
"type": "SortNode",
"dependencies": [
3
],
"id": 4,
"estimatedCost": 56166.713176593075,
"estimatedNrItems": 5310,
"elements": [
{
"inVariable": {
"id": 3,
"name": "3"
},
"ascending": true
}
],
"stable": true
},
{
"type": "AggregateNode",
"dependencies": [
4
],
"id": 5,
"estimatedCost": 61476.713176593075,
"estimatedNrItems": 5310,
"aggregates": [
{
"outVariable": {
"id": 1,
"name": "profile"
},
"inVariable": {
"id": 3,
"name": "3"
}
}
],
"outVariable": {
"id": 2,
"name": "profiles"
}
},
{
"type": "CalculationNode",
"dependencies": [
5
],
"id": 6,
"estimatedCost": 66786.71317659307,
"estimatedNrItems": 5310,
"expression": {
"type": "array",
"subNodes": [
{
"type": "array element",
"name": "Profile",
"subNodes": [
{
"type": "reference",
"name": "profile",
"id": 1
}
]
},
{
"type": "array element",
"name": "Count",
"subNodes": [
{
"type": "function call",
"name": "LENGTH",
"subNodes": [
{
"type": "list",
"subNodes": [
{
"type": "reference",
"name": "profiles",
"id": 2
}
]
}
]
}
]
}
]
},
"outVariable": {
"id": 4,
"name": "4"
},
"canThrow": false
},
{
"type": "ReturnNode",
"dependencies": [
6
],
"id": 7,
"estimatedCost": 72096.71317659307,
"estimatedNrItems": 5310,
"inVariable": {
"id": 4,
"name": "4"
}
}
],
"rules": [],
"collections": [
{
"name": "LRQ",
"type": "read"
}
],
"variables": [
{
"id": 0,
"name": "q"
},
{
"id": 1,
"name": "profile"
},
{
"id": 4,
"name": "4"
},
{
"id": 2,
"name": "profiles"
},
{
"id": 3,
"name": "3"
}
],
"estimatedCost": 72096.71317659307,
"estimatedNrItems": 5310
},
"warnings": []
}
Update 2014-12-05:
Here are additional measures: Understood, thanks. Here's the output:
Execution of AQL_EXECUTE('FOR q IN LRQ FILTER q.LongRunningQuery.Profile == "Admin" LIMIT 1 RETURN q.LongRunningQuery.Profile', {}, { profile : true }).profile --> { "initializing" : 0, "parsing" : 0, "optimizing ast" : 15.364980936050415, "instanciating plan" : 0, "optimizing plan" : 0, "executing" : 0 }
Execution of AQL_EXECUTE('FOR q IN LRQ COLLECT profile = q.LongRunningQuery.Profile INTO profiles RETURN { "Profile" : profile, "Count" : LENGTH(profiles)}', {}, { profile : true }).profile --> { "initializing" : 0, "parsing" : 0, "optimizing ast" : 0, "instanciating plan" : 0, "optimizing plan" : 0, "executing" : 77.88313102722168 }
Update 19.12.2014:
Since 2.3.2 the execution plan for the query arangosh [_system]> stmt2 = db._createStatement('FOR q IN LRQ COLLECT profile = q.LongRunningQuery.Profile INTO profiles RETURN { "Profile" : profile, "Count" : LENGTH(profiles)} ')
looks like this:
arangosh [_system]> stmt2.explain()
{
"plan" : {
"nodes" : [
{
"type" : "SingletonNode",
"dependencies" : [ ],
"id" : 1,
"estimatedCost" : 1,
"estimatedNrItems" : 1
},
{
"type" : "IndexRangeNode",
"dependencies" : [
1
],
"id" : 8,
"estimatedCost" : 5311,
"estimatedNrItems" : 5310,
"database" : "_system",
"collection" : "LRQ",
"outVariable" : {
"id" : 0,
"name" : "q"
},
"ranges" : [
[ ]
],
"index" : {
"type" : "skiplist",
"id" : "530975525379",
"unique" : false,
"fields" : [
"LongRunningQuery.Profile"
]
},
"reverse" : false
},
{
"type" : "CalculationNode",
"dependencies" : [
8
],
"id" : 3,
"estimatedCost" : 10621,
"estimatedNrItems" : 5310,
"expression" : {
"type" : "attribute access",
"name" : "Profile",
"subNodes" : [
{
"type" : "attribute access",
"name" : "LongRunningQuery",
"subNodes" : [
{
"type" : "reference",
"name" : "q",
"id" : 0
}
]
}
]
},
"outVariable" : {
"id" : 3,
"name" : "3"
},
"canThrow" : false
},
{
"type" : "AggregateNode",
"dependencies" : [
3
],
"id" : 5,
"estimatedCost" : 15931,
"estimatedNrItems" : 5310,
"aggregates" : [
{
"outVariable" : {
"id" : 1,
"name" : "profile"
},
"inVariable" : {
"id" : 3,
"name" : "3"
}
}
],
"outVariable" : {
"id" : 2,
"name" : "profiles"
}
},
{
"type" : "CalculationNode",
"dependencies" : [
5
],
"id" : 6,
"estimatedCost" : 21241,
"estimatedNrItems" : 5310,
"expression" : {
"type" : "array",
"subNodes" : [
{
"type" : "array element",
"name" : "Profile",
"subNodes" : [
{
"type" : "reference",
"name" : "profile",
"id" : 1
}
]
},
{
"type" : "array element",
"name" : "Count",
"subNodes" : [
{
"type" : "function call",
"name" : "LENGTH",
"subNodes" : [
{
"type" : "list",
"subNodes" : [
{
"type" : "reference",
"name" : "profiles",
"id" : 2
}
]
}
]
}
]
}
]
},
"outVariable" : {
"id" : 4,
"name" : "4"
},
"canThrow" : false
},
{
"type" : "ReturnNode",
"dependencies" : [
6
],
"id" : 7,
"estimatedCost" : 26551,
"estimatedNrItems" : 5310,
"inVariable" : {
"id" : 4,
"name" : "4"
}
}
],
"rules" : [
"use-index-for-sort"
],
"collections" : [
{
"name" : "LRQ",
"type" : "read"
}
],
"variables" : [
{
"id" : 0,
"name" : "q"
},
{
"id" : 1,
"name" : "profile"
},
{
"id" : 4,
"name" : "4"
},
{
"id" : 2,
"name" : "profiles"
},
{
"id" : 3,
"name" : "3"
}
],
"estimatedCost" : 26551,
"estimatedNrItems" : 5310
},
"warnings" : [ ],
"stats" : {
"rulesExecuted" : 25,
"rulesSkipped" : 0,
"plansCreated" : 1
}
}
COLLECToperation. A bug has been reported for this here: github.com/triAGENS/ArangoDB/issues/1107 - stj