Uploaded image for project: 'Couchbase Server'
  1. Couchbase Server
  2. MB-40177

FTS:SystemTest:err: grpc_client: query got status code: 500 for slow-queries

    XMLWordPrintable

Details

    • 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

          Activity

            People

              girish.benakappa Girish Benakappa
              girish.benakappa Girish Benakappa
              Votes:
              0 Vote for this issue
              Watchers:
              4 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved:

                Gerrit Reviews

                  There are no open Gerrit changes

                  PagerDuty