I have a slight missunderstanding between my expectations of Couchbase query performance and reality, but especially some specific parameters when I do an EXPLAIN
and peeak into the plan of that query. Namely I got a regular travel-sample
bucket, nothing fancy there. I’ve added a simple index to it:
CREATE INDEX `def_country` ON `travel-sample`(`country`)
Now running a pretty simple query like this:
SELECT country, COUNT(*) FROM `travel-sample` GROUP BY country;
gives me
{
"plan": {
"#operator": "Sequence",
"~children": [
{
"#operator": "PrimaryScan",
"index": "def_primary",
"keyspace": "travel-sample",
"namespace": "default",
"using": "gsi"
},
{
"#operator": "Fetch",
"keyspace": "travel-sample",
"namespace": "default"
},
{
"#operator": "Parallel",
"~child": {
"#operator": "Sequence",
"~children": [
{
"#operator": "InitialGroup",
"aggregates": [
"count(*)"
],
"group_keys": [
"(`travel-sample`.`country`)"
]
}
]
}
},
{
"#operator": "IntermediateGroup",
"aggregates": [
"count(*)"
],
"group_keys": [
"(`travel-sample`.`country`)"
]
},
{
"#operator": "FinalGroup",
"aggregates": [
"count(*)"
],
"group_keys": [
"(`travel-sample`.`country`)"
]
},
{
"#operator": "Parallel",
"~child": {
"#operator": "Sequence",
"~children": [
{
"#operator": "InitialProject",
"result_terms": [
{
"expr": "(`travel-sample`.`country`)"
},
{
"expr": "count(*)"
}
]
},
{
"#operator": "FinalProject"
}
]
}
}
]
},
"text": "SELECT country, COUNT(*) FROM `travel-sample` GROUP BY country;"
}
and this
{
"#operator": "Sequence",
"#stats": {
"#phaseSwitches": 2,
"execTime": "2.728µs",
"kernTime": "593.943261ms"
},
"~children": [
{
"#operator": "Authorize",
"#stats": {
"#phaseSwitches": 4,
"execTime": "5.416µs",
"kernTime": "591.015119ms",
"servTime": "2.88189ms"
},
"privileges": {
"List": [
{
"Target": "default:travel-sample",
"Priv": 7
}
]
},
"~child": {
"#operator": "Sequence",
"#stats": {
"#phaseSwitches": 3,
"execTime": "4.336µs",
"kernTime": "591.006439ms"
},
"~children": [
{
"#operator": "PrimaryScan",
"#stats": {
"#itemsOut": 31591,
"#phaseSwitches": 126367,
"execTime": "59.901175ms",
"kernTime": "495.567107ms",
"servTime": "21.223821ms"
},
"index": "def_primary",
"keyspace": "travel-sample",
"namespace": "default",
"using": "gsi",
"#time_normal": "00:00.0811",
"#time_absolute": 0.081124996
},
{
"#operator": "Fetch",
"#stats": {
"#itemsIn": 31591,
"#itemsOut": 31591,
"#phaseSwitches": 126495,
"execTime": "38.970644ms",
"kernTime": "52.476685ms",
"servTime": "498.146292ms"
},
"keyspace": "travel-sample",
"namespace": "default",
"#time_normal": "00:00.5371",
"#time_absolute": 0.537116936
},
{
"#operator": "Parallel",
"#stats": {
"#phaseSwitches": 3,
"execTime": "81.6µs",
"kernTime": "590.403294ms"
},
"copies": 6,
"~child": {
"#operator": "Sequence",
"#stats": {
"#phaseSwitches": 18,
"execTime": "13.79µs",
"kernTime": "3.539700556s"
},
"~children": [
{
"#operator": "InitialGroup",
"#stats": {
"#itemsIn": 31591,
"#itemsOut": 24,
"#phaseSwitches": 63260,
"execTime": "617.396284ms",
"kernTime": "2.922209191s"
},
"aggregates": [
"count(*)"
],
"group_keys": [
"(`travel-sample`.`country`)"
],
"#time_normal": "00:00.6173",
"#time_absolute": 0.617396284
}
],
"#time_normal": "00:00.0000",
"#time_absolute": 0.000013789999999999998
},
"#time_normal": "00:00.0000",
"#time_absolute": 0.00008159999999999999
},
{
"#operator": "IntermediateGroup",
"#stats": {
"#itemsIn": 24,
"#itemsOut": 4,
"#phaseSwitches": 61,
"execTime": "185.312µs",
"kernTime": "590.502024ms"
},
"aggregates": [
"count(*)"
],
"group_keys": [
"(`travel-sample`.`country`)"
],
"#time_normal": "00:00.0001",
"#time_absolute": 0.000185312
},
{
"#operator": "FinalGroup",
"#stats": {
"#itemsIn": 4,
"#itemsOut": 4,
"#phaseSwitches": 21,
"execTime": "39.269µs",
"kernTime": "590.704876ms"
},
"aggregates": [
"count(*)"
],
"group_keys": [
"(`travel-sample`.`country`)"
],
"#time_normal": "00:00.0000",
"#time_absolute": 0.000039269
},
{
"#operator": "Parallel",
"#stats": {
"#phaseSwitches": 5,
"execTime": "112.872µs",
"kernTime": "590.869401ms"
},
"copies": 6,
"~child": {
"#operator": "Sequence",
"#stats": {
"#phaseSwitches": 18,
"execTime": "10.964µs",
"kernTime": "3.542669702s"
},
"~children": [
{
"#operator": "InitialProject",
"#stats": {
"#itemsIn": 4,
"#itemsOut": 4,
"#phaseSwitches": 34,
"execTime": "100.228µs",
"kernTime": "3.542359879s"
},
"result_terms": [
{
"expr": "(`travel-sample`.`country`)"
},
{
"expr": "count(*)"
}
],
"#time_normal": "00:00.0001",
"#time_absolute": 0.00010022799999999999
},
{
"#operator": "FinalProject",
"#stats": {
"#itemsIn": 4,
"#itemsOut": 4,
"#phaseSwitches": 58,
"execTime": "18.179µs",
"kernTime": "3.542555127s"
},
"#time_normal": "00:00.0000",
"#time_absolute": 0.000018179
}
],
"#time_normal": "00:00.0000",
"#time_absolute": 0.000010964
},
"#time_normal": "00:00.0001",
"#time_absolute": 0.000112872
}
],
"#time_normal": "00:00.0000",
"#time_absolute": 0.0000043360000000000005
},
"#time_normal": "00:00.0028",
"#time_absolute": 0.0028873059999999996
},
{
"#operator": "Stream",
"#stats": {
"#itemsIn": 4,
"#itemsOut": 4,
"#phaseSwitches": 15,
"execTime": "3.533µs",
"kernTime": "593.933895ms"
},
"#time_normal": "00:00.0000",
"#time_absolute": 0.000003533
}
],
"~versions": [
"1.7.0-N1QL",
"5.0.0-2873-enterprise"
],
"#time_normal": "00:00.0000",
"#time_absolute": 0.0000027280000000000004
}
Overall it feels slow. Like a second to execute this simple query. And what is the most interesting in the result is the kernTime
.
I am running here a docker image, both stable and beta sandbox, and the result is pretty much the same. Minimal difference if any. Server is pretty new E5, doing absolutely nothing else. But checked it on my poor, old laptop and it gives me similar, but even slower result. kernTime
to blame and I do not get it…
Any ideas? At this point all of my team wants to go back to MongoDB, but I really, really hate their clustering approach…