Understanding Query plan stats

Couchbase Server
1

Hello,
I’m trying to discover more cool stuff in Couchbase and just came across the “Plan” tab in Query Workbench.
My question is about the “#stats” section for each step of planning.
I’ve tried to analyze a particular query on Travel Sample, and the plan contains the below two steps (image #1).

query-plan
query-plan.png860×730 146 KB

I’ve noticed two fields in “#stats” section, “#itemsIn” and “#itemsOut”. I anticipated seeing equal “#itemsOut” and “#itemsIn” fields for consequent steps. However, they are different and I wonder why?
As you see in image #2, the “PrimaryScan3” step returns (#itemsOut) 6289 items,
whereas in image #3, the “Fetch” step receives (#itemsIn) only 5777 items.

Can you please shed some light on this?
Also, I found that not always those stats contain information about the count of in-and-out items.

2

Checkout Monitoring section.

Please post the query if still have question because it depends on query.
Example: If query has LIMIT clause, once LIMIT clause is satisfied it can stop remaining query. As query plan operators runs simultaneously those can will be terminated and can have different stats.

3

Hi @vsr1,
Thanks for your reply and the reference to the guide.
Unfortunately, it didn’t help much with my question. Here’s another query I tried to run on Travel Sample without using any indexes:

SELECT * FROM `travel-sample`
WHERE city like "San Francisco"
LIMIT 100;

Also, I’ve noticed that there’s a mismatch between #itemsIn/#itemsOut, when using a predicate with LIMIT without any index. For me, looks like it works after each planning step. I wonder how does it work and what are other operators which can cause such behavior?

4

With out indexes couchbase will not work.
Please execute query in Query Workbench and go to Plan Text Tab and see what index used and you have all the details.

SELECT * FROM `travel-sample`
WHERE city like "San Francisco"
LIMIT 100; 

{
  "#operator": "Sequence",
  "#stats": {
    "#phaseSwitches": 1,
    "execTime": "4.627µs"
  },
  "~children": [
    {
      "#operator": "Authorize",
      "#stats": {
        "#phaseSwitches": 3,
        "execTime": "17.72µs",
        "servTime": "949.582µs"
      },
      "privileges": {
        "List": [
          {
            "Target": "default:travel-sample",
            "Priv": 7
          }
        ]
      },
      "~child": {
        "#operator": "Sequence",
        "#stats": {
          "#phaseSwitches": 1,
          "execTime": "26.623µs"
        },
        "~children": [
          {
            "#operator": "Sequence",
            "#stats": {
              "#phaseSwitches": 2,
              "execTime": "3.445142ms",
              "kernTime": "855ns",
              "state": "running"
            },
            "~children": [
              {
                "#operator": "IndexScan3",
                "#stats": {
                  "#itemsOut": 100,
                  "#phaseSwitches": 403,
                  "execTime": "305.495µs",
                  "kernTime": "86.314µs",
                  "servTime": "1.516838ms"
                },
                "index": "def_city",
                "index_id": "3998e326a89ad798",
                "index_projection": {
                  "primary_key": true
                },
                "keyspace": "travel-sample",
                "limit": "100",
                "namespace": "default",
                "spans": [
                  {
                    "exact": true,
                    "range": [
                      {
                        "high": "\"San Francisco\"",
                        "inclusion": 3,
                        "low": "\"San Francisco\""
                      }
                    ]
                  }
                ],
                "using": "gsi",
                "#time_normal": "00:00.0018",
                "#time_absolute": 0.001822333
              },
              {
                "#operator": "Fetch",
                "#stats": {
                  "#itemsIn": 100,
                  "#itemsOut": 100,
                  "#phaseSwitches": 417,
                  "execTime": "604.564µs",
                  "kernTime": "1.83634ms",
                  "servTime": "16.457019ms"
                },
                "keyspace": "travel-sample",
                "namespace": "default",
                "#time_normal": "00:00.0170",
                "#time_absolute": 0.017061582999999998
              },
              {
                "#operator": "Sequence",
                "#stats": {
                  "#phaseSwitches": 2,
                  "execTime": "3.56649ms",
                  "kernTime": "808ns",
                  "state": "running"
                },
                "~children": [
                  {
                    "#operator": "Filter",
                    "#stats": {
                      "#itemsIn": 100,
                      "#itemsOut": 100,
                      "#phaseSwitches": 403,
                      "execTime": "1.794375ms",
                      "kernTime": "17.207091ms"
                    },
                    "condition": "((`travel-sample`.`city`) like \"San Francisco\")",
                    "#time_normal": "00:00.0017",
                    "#time_absolute": 0.001794375
                  },
                  {
                    "#operator": "InitialProject",
                    "#stats": {
                      "#itemsIn": 100,
                      "#itemsOut": 100,
                      "#phaseSwitches": 307,
                      "execTime": "304.983µs",
                      "kernTime": "9.072484ms"
                    },
                    "result_terms": [
                      {
                        "expr": "self",
                        "star": true
                      }
                    ],
                    "#time_normal": "00:00.0003",
                    "#time_absolute": 0.000304983
                  },
                  {
                    "#operator": "FinalProject",
                    "#stats": {
                      "#itemsIn": 100,
                      "#itemsOut": 100,
                      "#phaseSwitches": 201,
                      "execTime": "238.848µs"
                    },
                    "#time_normal": "00:00.0002",
                    "#time_absolute": 0.000238848
                  }
                ],
                "#time_normal": "00:00.0035",
                "#time_absolute": 0.00356649
              }
            ],
            "#time_normal": "00:00.0034",
            "#time_absolute": 0.003445142
          },
          {
            "#operator": "Limit",
            "#stats": {
              "#itemsIn": 100,
              "#itemsOut": 100,
              "#phaseSwitches": 301,
              "execTime": "201.639µs",
              "kernTime": "27.156854ms"
            },
            "expr": "100",
            "#time_normal": "00:00.0002",
            "#time_absolute": 0.000201639
          }
        ],
        "#time_normal": "00:00.0000",
        "#time_absolute": 0.000026623000000000002
      },
      "#time_normal": "00:00.0009",
      "#time_absolute": 0.0009673020000000001
    },
    {
      "#operator": "Stream",
      "#stats": {
        "#itemsIn": 100,
        "#itemsOut": 100,
        "#phaseSwitches": 403,
        "execTime": "220.352µs",
        "kernTime": "38.70263ms"
      },
      "#time_normal": "00:00.0002",
      "#time_absolute": 0.000220352
    }
  ],
  "~versions": [
    "2.0.0-N1QL",
    "6.0.3-2851-enterprise"
  ],
  "#time_normal": "00:00.0000",
  "#time_absolute": 0.000004627
}

Above query use def_city CREATE INDEX def_city ON travel-sample(city)
The predicate is city like “San Francisco” Able to push exactly to Index Scan can be found in the spans. Query planner knows predicate sent to index scan and no false positives possible and query will not eliminate any further so it passed LIMIT to indexer can be seen in IndexScan section.

The above book has all the details in Optimization/Index section.

5

@vsr1 I know that with indexes it works as expected. I’m wondering about the case when there’s no index. And I don’t get what do you mean by the following?:

With out indexes couchbase will not work.

6

Couchbase Query required at least one qualified index. without qualified index query returns error.

7

Hmm, first time I’m hearing about that. Is it documented anywhere?
Also in Query Workbench it works just fine and returns normal results without any index:

image
image.png2048×1532 226 KB

8

When travel-sample installed it will automatically creates few indexes.
You can check one of the following way.

  • Click Indexes on left side bar of Web UI
  • Click on EXPLAIN in query work bench too see which index query using
  • Execute query an do to Plan Text Tab in query work bench too see which index query using

https://docs.couchbase.com/server/4.5/getting-started/first-n1ql-query.html

https://learn.couchbase.com/store/404675-cb110-intro-to-n1ql-sql-for-json

https://docs.couchbase.com/server/4.5/indexes/indexing-overview.html
Read Optimization and Index sections of https://blog.couchbase.com/wp-content/uploads/2017/10/N1QL-A-Practical-Guide-2nd-Edition.pdf
https://blog.couchbase.com/create-right-index-get-right-performance/

9

@vsr1
Thanks for the links.
Here’s the plain text EXPLAIN result for the above query.

  {
"plan": {
  "#operator": "Sequence",
  "~children": [
    {
      "#operator": "Sequence",
      "~children": [
        {
          "#operator": "PrimaryScan3",
          "index": "def_primary",
          "index_projection": {
            "primary_key": true
          },
          "keyspace": "travel-sample",
          "namespace": "default",
          "using": "gsi"
        },
        {
          "#operator": "Fetch",
          "keyspace": "travel-sample",
          "namespace": "default"
        },
        {
          "#operator": "Parallel",
          "~child": {
            "#operator": "Sequence",
            "~children": [
              {
                "#operator": "Filter",
                "condition": "((`travel-sample`.`city`) like \"San Francisco\")"
              },
              {
                "#operator": "InitialProject",
                "result_terms": [
                  {
                    "expr": "self",
                    "star": true
                  }
                ]
              },
              {
                "#operator": "FinalProject"
              }
            ]
          }
        }
      ]
    },
    {
      "#operator": "Limit",
      "expr": "100"
    }
  ]
},
"text": "SELECT * FROM `travel-sample`\nWHERE city like \"San Francisco\"\nLIMIT 100;"
}

As you can see there’s no index being run. Yes, travel-sample comes with an index, but I’ve deleted that for purpose in order to check. So, that’s working correctly without any index and it is not failing as you said.

10 
There is Primary index called def_primary on the bucket. Without that  explain will not work.

DROP INDEX `travel-sample`.def_primary;

And try again.

11

@vsr1 ah, now I see what you mean.
I thought if there’s an index used in query, EXPLAIN always shows a step with the operator name “IndexScan”.
So, the primary index goes with the operator name “PrimaryScan”.

After learning this, my original question is changed a bit, that is: When using a secondary index (when EXPLAIN shows IndexScan step), the values of “#itemsOut” and “#itemsIn” for consecutive steps are equal. However, when using only primary index (when EXPLAIN shows PrimaryScan step), those values differ and it’s not clear what affected on that.

12

Primary index can be used as secondary index scan when there is predicate on document key.
I will advise read Indexing and Optimize sections of the pdf posted earlier to better understand.

The following page describes how the predicate is transformed to indexScan Ranges.

https://docs.couchbase.com/server/5.5/performance/index-scans.html

13

@vsr1 I was looking into the monitoring stats of couchbase. I see the query ops statistics and was a little confused. i Read on another thread that when you have a select and do a “use keys” operation the query service bypasses the index nodes and goes straight to data (acting like a key value lookup.) But we dont see a query operation in the statistics occuring. we see it as a KV i believe. Is this accurate behavior?

Thanks in Advance

14

You should count into number of request/sec Graps under (Bucket===>Stastics==>Query)

1 Like