Details
-
Bug
-
Resolution: Fixed
-
Major
-
6.6.0
-
Untriaged
-
1
-
Unknown
Description
Build: 6.6.0 build 7843
Test: -test tests/n1ql/test_n1ql_fts_flexindex.yml -scope tests/n1ql/scope_flex_index_12nodes.yml
Scale: 2
Seeing below error messages for some of the queries:
Node : 172.23.120.77
2020-06-26T08:30:14.478-07:00 [INFO] grpc_client: recv err: rpc error: code = Unknown desc = context deadline exceeded
|
2020-06-26T08:30:14.478-07:00 [WARN] grpc_client: Query() returned error from host: 172.23.123.24:9130, err: grpc_client: query got status code: 500, resp: &bleve.SearchResult{Status:(*bleve.SearchStatus)(0xc01a702820), Request:(*bleve.SearchRequest)(0xc006dcf810), Hits:search.DocumentMatchCollection(nil), Total:0x0, MaxScore:0, Took:0, Facets:search.FacetResults(nil)}, err: rpc error: code = Unknown desc = context deadline exceeded -- cbft.(*GrpcClient).SearchInContext.func1() at grpc_client.go:158
|
2020-06-26T08:30:14.665-07:00 [INFO] grpc_client: recv err: rpc error: code = Unknown desc = context deadline exceeded
|
2020-06-26T08:30:14.665-07:00 [WARN] grpc_client: Query() returned error from host: 172.23.120.86:9130, err: grpc_client: query got status code: 500, resp: &bleve.SearchResult{Status:(*bleve.SearchStatus)(0xc01a702620), Request:(*bleve.SearchRequest)(0xc006dcf760), Hits:search.DocumentMatchCollection(nil), Total:0x0, MaxScore:0, Took:0, Facets:search.FacetResults(nil)}, err: rpc error: code = Unknown desc = context deadline exceeded -- cbft.(*GrpcClient).SearchInContext.func1() at grpc_client.go:158
|
2020-06-26T08:30:14.682-07:00 [WARN] grpc_util: slow-query index: bucket2_idx1, query: {"query":{"min":200,"max":1000,"inclusive_min":true,"inclusive_max":true,"field":"rating"},"size":0,"from":0,"highlight":null,"fields":null,"facets":null,"explain":false,"sort":null,"includeLocations":false,"score":"none","search_after":null,"search_before":null}, duration: 9.794395072s, err: <nil> -- cbft.updateRpcFocusStats() at grpc_util.go:299
|
Query and error looks like below:
{
|
"completed_requests": {
|
"clientContextID": "query_thread_0",
|
"elapsedTime": "2m20.341071127s",
|
"errorCount": 1,
|
"errors": [
|
{
|
"cause": "rpc error: code = DeadlineExceeded desc = grpc_server: Search searchInContext err: bleve: QueryBleve remote client returned status: 500 body: null",
|
"code": 5000,
|
"key": "Internal Error",
|
"message": "n1fty: response_handler: stream.Recv, err "
|
}
|
],
|
"node": "172.23.96.122:8091",
|
"phaseCounts": {
|
"fetch": 2168468,
|
"filter": 2132112,
|
"ftsSearch": 2168464
|
},
|
"phaseOperators": {
|
"authorize": 1,
|
"fetch": 1,
|
"filter": 1,
|
"ftsSearch": 1
|
},
|
"phaseTimes": {
|
"authorize": "28.059µs",
|
"fetch": "2m14.817682832s",
|
"filter": "35.787332306s",
|
"ftsSearch": "14.04189358s",
|
"instantiate": "32.682µs",
|
"parse": "1.499177ms",
|
"plan": "3.101801ms",
|
"run": "2m20.336337331s"
|
},
|
"remoteAddr": "172.23.104.254:50346",
|
"requestId": "4618a554-f1ce-4f72-b5e8-ca46ecfe9dc3",
|
"requestTime": "2020-06-26T08:32:25.212-07:00",
|
"resultCount": 1,
|
"resultSize": 64,
|
"scanConsistency": "unbounded",
|
"serviceTime": "2m20.341015133s",
|
"state": "completed",
|
"statement": "select result,AVG(rating),MIN(rating),MAX(rating) from `other-2` use index (using fts) where rating >= 200 and rating <= 1000 and `type`=\"gideon\" group by result limit 1000\n",
|
"userAgent": "couchbase-java-client/${project.version} (git: ${git.commit.id.describe}, core: ${git.commit.id.describe}) (Linux/3.10.0-1062.9.1.el7.x86_64 amd64; OpenJDK 64-Bit Server VM 1.8.0_252-b09)",
|
"users": "Administrator"
|
}
|
}
|
Logs:
cbcollect logs:
url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1593188813/collectinfo-2020-06-26T162655-ns_1%40172.23.120.73.zip
url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1593188813/collectinfo-2020-06-26T162655-ns_1%40172.23.120.77.zip
url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1593188813/collectinfo-2020-06-26T162655-ns_1%40172.23.120.86.zip
url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1593188813/collectinfo-2020-06-26T162655-ns_1%40172.23.121.77.zip
url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1593188813/collectinfo-2020-06-26T162655-ns_1%40172.23.123.24.zip
url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1593188813/collectinfo-2020-06-26T162655-ns_1%40172.23.123.25.zip
url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1593188813/collectinfo-2020-06-26T162655-ns_1%40172.23.123.26.zip
url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1593188813/collectinfo-2020-06-26T162655-ns_1%40172.23.96.122.zip
url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1593188813/collectinfo-2020-06-26T162655-ns_1%40172.23.96.14.zip
url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1593188813/collectinfo-2020-06-26T162655-ns_1%40172.23.96.18.zip
url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1593188813/collectinfo-2020-06-26T162655-ns_1%40172.23.96.48.zip
url : https://cb-jira.s3.us-east-2.amazonaws.com/logs/systestmon-1593188813/collectinfo-2020-06-26T162655-ns_1%40172.23.97.74.zip
A question: Flex queries here are run with timeout of 10 mins, is this timeout being passed/used while querying FTS index by n1fty?
Attachments
Issue Links
For Gerrit Dashboard: MB-40177 | ||||||
---|---|---|---|---|---|---|
# | Subject | Branch | Project | Status | CR | V |
133396,3 | MB-40177: Setting a default timeout (120s) for FLEX queries | master | n1fty | Status: MERGED | +2 | +1 |
133763,6 | MB-40177: Propagating ctl.timeout for search requests | master | n1fty | Status: MERGED | +2 | +1 |
133765,5 | MB-40177: Setting N1QL context timeout for all FTS queries | master | n1fty | Status: MERGED | +2 | +1 |