Query takes 75 seconds when using rest api/sdk, but 20ms in cbq

Hi,

I just noticed that response time increased to 75 seconds for certain queries.

When I run the same query directly in cbq console, it works super fast. I get under 20ms. When I copy the same query and use rest api (port 8093), then I get 75 seconds again.

I don’t even know where to start to debug. I’m on 4.0 CE and using PHP SDK. Tested both directly using rest api as well.

One thing I noticed very weird is…that it is fast when I don’t use parameterized query

Takes 75+ seconds:
curl -v http://localhost:8093/query/service -d 'statement=select * from bucket where form=$1&args=["value-here"]'

Fast:
curl -v http://localhost:8093/query/service -d 'statement=select * from bucket where form=value-here'

We have 593768 documents so far.

Could someone give a hint?

1 Like

Happy to help.

To begin with, your queries aren’t quite identical. You would need to enclose the value-here in quotes in the second form to get the same results.

If that’s not the problem, let’s try having a look at your query plan and indexes. You can get the query plans by prepending EXPLAIN to each query. You can get the set of indexes using this query: SELECT * FROM system:indexes .

Hi @johan_larson,

missing quote is my editing issue. They have the same value.

I’ve already used EXPLAIN to confirm that the query takes indexes.

It cannot be index issue as the query works just fine in cbq and without &args parameter (parameterized query).

I’m not sure what the problem is, but let’s try a few things.

Can you confirm that both forms (parameterized and unparameterized) of the curl query use the same query plan? (Based on EXPLAIN)

Also, I see you are on 4.0. Could you check whether the problem also happens on 4.5? The developer preview is available now, and the beta should be available some time in May.

@johan_larson

Okay…I think I found the issue.

The following explain shows that it does PrimaryScan.

curl -v http://localhost:8093/query/service -d 'statement=explain select * from bucket where form=$1&args=["product_type"]'

This takes correct index scan

curl -v http://localhost:8093/query/service -d 'statement=select * from mybucket where form="product_type"'

What’s the difference between two? I got the first example from the documentation. AND i’m also having the same issue with PHP SDK.

A primary scan is the equivalent of a table scan in the relational world. It scans all the records themselves.

An index scan does looks at the index first, determining what records actually should be retrieved and then pulls them individually?

So in this case the slow query is doing an index scan? And the fast one is doing a primary scan? That’s possible if the predicate is often true.

You can hardcode the index to use, like this: http://developer.couchbase.com/documentation/server/4.0/n1ql/n1ql-language-reference/hints.html

It happens for all queries. Isn’t it considered a bug though?

I mean it makes SDK and rest api unusable.

I think hardcoding index is a workaround.

Can someone else comment on this? I should not be the one who’s having this issue.

@geraldss Sorry for pinging you, but do you have any ideas on it?

Hi @moon0326, this has been fixed in 4.5, and I believe 4.1 as well. Please test with those, especially the upcoming 4.5 Beta.

As @johan_larson pointed out, the difference is primary scan vs. index scan. We have fixed this so that index scans can be used with parametrized queries.

Ping us anytime.

Thanks,
Gerald

@geraldss Thank you geraldss.

We gave up on 4.0 CE and testing out 4.1 enterprise as we are going to be using enterprise anyway.

This is not fixed in 4.1. We have the same issue. I really think we can’t afford using 4.5 at this point.

For now, we stopped using parameterized queries.

It sounds like we have no choice but use just regular queries.

My apologies, I was hoping this was fixed in 4.1. We will also verify this internally on 4.1 and 4.1.1 (parametrized queries and index scans).

Could you please let us know exact version you are using.

we are on 4.1.0-5005 Enterprise Edition (build-5005)

I have tried the following index and curl statement and it uses index.

create index ix2 on default(form);

curl -v http://localhost:8093/query/service -d ‘statement=explain select * from default where form=$1&args=[“product_type”]’

  • About to connect() to localhost port 8093 (#0)
  • Trying ::1… connected
  • Connected to localhost (::1) port 8093 (#0)

POST /query/service HTTP/1.1
User-Agent: curl/7.19.7 (x86_64-redhat-linux-gnu) libcurl/7.19.7 NSS/3.19.1 Basic ECC zlib/1.2.3 libidn/1.18 libssh2/1.4.2
Host: localhost:8093
Accept: /
Content-Length: 75
Content-Type: application/x-www-form-urlencoded

< HTTP/1.1 200 OK
< Content-Length: 2297
< Content-Type: application/json; version=1.0.0
< Date: Wed, 20 Apr 2016 20:23:44 GMT
<
{
“requestID”: “0e931a4c-7dd5-425d-9a58-c5f6d16467fe”,
“signature”: “json”,
“results”: [
{
#operator”: “Sequence”,
“~children”: [
{
#operator”: “IndexScan”,
“index”: “ix2”,
“keyspace”: “default”,
“limit”: 9.223372036854776e+18,
“namespace”: “default”,
“spans”: [
{
“Range”: {
“High”: [
“$1”
],
“Inclusion”: 3,
“Low”: [
“$1”
]
},
“Seek”: null
}
],
“using”: “gsi”
},
{
#operator”: “Parallel”,
“~child”: {
#operator”: “Sequence”,
“~children”: [
{
#operator”: “Fetch”,
“keyspace”: “default”,
“namespace”: “default”
},
{
#operator”: “Filter”,
“condition”: “((default.form) = $1)”
},
{
#operator”: “InitialProject”,
“result_terms”: [
{
“star”: true
}
]
},
{
#operator”: “FinalProject”
}
]
}
}
]
}
],
“status”: “success”,
“metrics”: {
“elapsedTime”: “3.361708ms”,
“executionTime”: “3.241166ms”,
“resultCount”: 1,
“resultSize”: 2001
}
}

@vsr1 Thank you for the output.

Here is mine from the server.

[myname@myserver-mds-query-i-4a0befb2 bin]$ ./couchbase-server -v
Couchbase Server 4.1.0-5005 (EE)
[myname@myserver-mds-query-i-4a0befb2 bin]$ curl -v http://localhost:8093/query/service -d 'statement=explain select * from catalog where form=$1&args=["product_type"]'
*   Trying 127.0.0.1...
* Connected to localhost (127.0.0.1) port 8093 (#0)
> POST /query/service HTTP/1.1
> User-Agent: curl/7.40.0
> Host: localhost:8093
> Accept: */*
> Content-Length: 75
> Content-Type: application/x-www-form-urlencoded
>
* upload completely sent off: 75 out of 75 bytes
< HTTP/1.1 200 OK
< Content-Length: 1811
< Content-Type: application/json; version=1.0.0
< Date: Wed, 20 Apr 2016 20:44:57 GMT
<
{
    "requestID": "c2a4a9dc-b799-43dd-b3a8-6857cd2be59f",
    "signature": "json",
    "results": [
        {
            "#operator": "Sequence",
            "~children": [
                {
                    "#operator": "PrimaryScan",
                    "index": "#primary",
                    "keyspace": "catalog",
                    "namespace": "default",
                    "using": "gsi"
                },
                {
                    "#operator": "Parallel",
                    "~child": {
                        "#operator": "Sequence",
                        "~children": [
                            {
                                "#operator": "Fetch",
                                "keyspace": "catalog",
                                "namespace": "default"
                            },
                            {
                                "#operator": "Filter",
                                "condition": "((`catalog`.`form`) = $1)"
                            },
                            {
                                "#operator": "InitialProject",
                                "result_terms": [
                                    {
                                        "expr": "self",
                                        "star": true
                                    }
                                ]
                            },
                            {
                                "#operator": "FinalProject"
                            }
                        ]
                    }
                }
            ]
        }
    ],
    "status": "success",
    "metrics": {
        "elapsedTime": "12.021468ms",
        "executionTime": "11.980412ms",
        "resultCount": 1,
        "resultSize": 1513
    }
}
* Connection #0 to host localhost left intact
[myname@myserver-mds-query-i-4a0befb2 bin]$ curl -v http://localhost:8093/query/service -d 'statement=explain select * from catalog where form="product_type"'
*   Trying 127.0.0.1...
* Connected to localhost (127.0.0.1) port 8093 (#0)
> POST /query/service HTTP/1.1
> User-Agent: curl/7.40.0
> Host: localhost:8093
> Accept: */*
> Content-Length: 65
> Content-Type: application/x-www-form-urlencoded
>
* upload completely sent off: 65 out of 65 bytes
< HTTP/1.1 200 OK
< Content-Length: 2321
< Content-Type: application/json; version=1.0.0
< Date: Wed, 20 Apr 2016 20:45:23 GMT
<
{
    "requestID": "5e185862-b496-4e07-a77e-cfe1a93e3cf5",
    "signature": "json",
    "results": [
        {
            "#operator": "Sequence",
            "~children": [
                {
                    "#operator": "IndexScan",
                    "index": "idx_product_type_form",
                    "keyspace": "catalog",
                    "namespace": "default",
                    "spans": [
                        {
                            "Range": {
                                "High": [
                                    "\"product_type\""
                                ],
                                "Inclusion": 3,
                                "Low": [
                                    "\"product_type\""
                                ]
                            }
                        }
                    ],
                    "using": "gsi"
                },
                {
                    "#operator": "Parallel",
                    "~child": {
                        "#operator": "Sequence",
                        "~children": [
                            {
                                "#operator": "Fetch",
                                "keyspace": "catalog",
                                "namespace": "default"
                            },
                            {
                                "#operator": "Filter",
                                "condition": "((`catalog`.`form`) = \"product_type\")"
                            },
                            {
                                "#operator": "InitialProject",
                                "result_terms": [
                                    {
                                        "expr": "self",
                                        "star": true
                                    }
                                ]
                            },
                            {
                                "#operator": "FinalProject"
                            }
                        ]
                    }
                }
            ]
        }
    ],
    "status": "success",
    "metrics": {
        "elapsedTime": "12.376166ms",
        "executionTime": "12.329222ms",
        "resultCount": 1,
        "resultSize": 2023
    }
}
* Connection #0 to host localhost left intact

Could you please post your index definition. Also run the following command in cbq and see if it uses index. Change bucket name and index name.

     explain select * from default where form=$1;
     explain select * from default use index (ix2) where form=$1;

I have conditional indexes for form value.

create index idx_example1_form on bucket(form) where form='example1' using GSI;
create index idx_example2_form on bucket(form) where form='example2' using GSI;
create index idx_example3_form on bucket(form) where form='example3' using GSI;

I’m now suspecting that my index definition might not be correct, but it still does not explain why I see IndexScan in cbq.

Both of these take PrimaryScan

 explain select * from default where form=$1;
 explain select * from default use index (ix2) where form=$1;

Update: created a new index without where clause and everything works as expected now. Is this considered a bug or am I understanding how index works incorrectly?

Can you create the following index:

create index idx_form on bucket(form);

And then run EXPLAIN for the parametrized query.

If you have conditional index to choose that index, the exact index condition needs be present in query where clause. This is expected.

Could you please provide more details on “but it still does not explain why I see IndexScan in cbq”

@geraldss I’ve updated my thread. It works if I create an index without where clause.

@vsr1

When I run the exact query in cbq without positional parameters, it takes index without specifying index condition. It looks like to me that it is a bug where rest api endpoint does not parse the positional parameters before sending the query to the query service.