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

Unable to find fts node in the very beginning of service swap rebalance

    XMLWordPrintable

Details

    • Bug
    • Resolution: Fixed
    • Critical
    • 5.5.0
    • 5.5.0
    • fts, ns_server
    • None
    • Untriaged
    • Centos 64-bit
    • Unknown

    Description

      Build
      5.5.0-2155

      Testcase
      ./testrunner -i /tmp/testexec.11676.ini get-cbcollect-info=True,get-logs=False,stop-on-failure=False,GROUP=P1 -t fts.moving_topology_fts.MovingTopFTS.swap_rebalance_during_querying,items=10000,cluster=D,F,replicas=0,num_queries=100,compare_es=True,num_queries=100,GROUP=P1

      /data/workspace/centos-p0-fts-vset00-00-moving-topology-P1/logs/testrunner-18-Mar-14_23-39-41/test_7, slave 172.23.105.89

      Steps:
      1. D, F(.103) cluster
      2. Create default index on default bucket with 10k docs, wait for indexing to complete
      3. Start swap rebalance .103 with .122
      4. Fire queries immediately, the logs below indicate that for 4s, pools/default rest api does not return any fts nodes in the cluster.

      [2018-03-14 23:55:19,319] - [fts_base:876] INFO - Creating fulltext-index default_index on 172.23.104.103
      		 
      [2018-03-14 23:55:19,320] - [rest_client:2667] INFO - {"params": {"store": {"mossStoreOptions": {}, "kvStoreName": "mossStore"}}, "name": "default_index", "planParams": {"numReplicas": 0, "maxPartitionsPerPIndex": 171}, "sourceName": "default", "sourceUUID": "", "sourceType": "couchbase", "type": "fulltext-index", "uuid": ""}
      		 
      [2018-03-14 23:55:19,344] - [rest_client:2674] INFO - Index default_index created
      		 
      [2018-03-14 23:55:19,345] - [fts_base:3515] INFO - Validating index distribution for default_index ...
      		 
      [2018-03-14 23:55:19,454] - [fts_base:3533] INFO - Validated: Number of PIndexes = 6
      		 
      [2018-03-14 23:55:19,478] - [fts_base:3545] INFO - Validated: Every pIndex serves 171 partitions or lesser
      		 
      [2018-03-14 23:55:19,478] - [fts_base:3569] INFO - Expecting num of partitions in each node in range 853-1024
      		 
      [2018-03-14 23:55:19,478] - [fts_base:3584] INFO - Validated: Node 6d04de90b6afba3267aace1e5f000193 houses 6 pindexes which serve 1024 partitions
      		 
      [2018-03-14 23:55:20,951] - [task:1228] INFO - Starting operation 'create' on Elastic Search ...
      		 
      [2018-03-14 23:55:21,529] - [data_helper:295] INFO - creating direct client 172.23.104.100:11210 default
      		 
      [2018-03-14 23:55:24,407] - [task:1262] INFO - 5000 documents bulk loaded into ES
      		 
      [2018-03-14 23:55:26,809] - [task:1262] INFO - 10000 documents bulk loaded into ES
      		 
      [2018-03-14 23:55:26,959] - [task:1267] INFO - ES index count for 'es_index': 10000
      		 
      [2018-03-14 23:55:27,314] - [fts_base:3920] INFO - Loading phase complete!
      		 
      [2018-03-14 23:55:27,394] - [rest_client:1896] INFO - http://172.23.104.100:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      [2018-03-14 23:55:27,418] - [fts_base:3433] INFO - Docs in bucket = 5000, docs in FTS index 'default_index': 5609, docs in ES index: 10000 
      [2018-03-14 23:55:33,472] - [rest_client:1896] INFO - http://172.23.104.100:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      [2018-03-14 23:55:33,504] - [fts_base:3433] INFO - Docs in bucket = 10000, docs in FTS index 'default_index': 10000, docs in ES index: 10000 
      [2018-03-14 23:55:33,581] - [fts_base:2572] INFO - Starting swap-rebalance [remove_node:[ip:172.23.104.103 port:8091 ssh_username:root]] -> [add_node:[ip:172.23.105.122 port:8091 ssh_username:root]] at C1 cluster 172.23.104.100
      		 
      [2018-03-14 23:55:34,164] - [rest_client:1997] INFO - Node versions in cluster [u'5.5.0-2155-enterprise', u'5.5.0-2155-enterprise']
      		 
      [2018-03-14 23:55:34,197] - [task:437] INFO - adding node 172.23.105.122:8091 to cluster
      		 
      [2018-03-14 23:55:34,197] - [rest_client:1215] INFO - adding remote node @172.23.105.122:8091 to this cluster @172.23.104.100:8091
      		 
      [2018-03-14 23:55:36,131] - [rest_client:1433] INFO - rebalance params : {'password': 'password', 'ejectedNodes': u'ns_1@172.23.104.103', 'user': 'Administrator', 'knownNodes': u'ns_1@172.23.104.100,ns_1@172.23.104.103,ns_1@172.23.105.122'}
      		 
      [2018-03-14 23:55:36,142] - [rest_client:1438] INFO - rebalance operation started
      		 
      [2018-03-14 23:55:36,143] - [task:1296] INFO - ----------------------------------------------------- Query # 1 ----------------------------------------------------
      		 
      [2018-03-14 23:55:36,167] - [rest_client:1971] INFO - Node 172.23.105.122 not part of cluster inactiveAdded
      		 
      [2018-03-14 23:55:36,168] - [fts_base:1075] ERROR - Error running query: No node in the cluster has 'fts' service enabled
      		 
      [2018-03-14 23:55:36,168] - [task:1300] INFO - Status: {}
      		 
      [2018-03-14 23:55:36,168] - [task:1324] INFO - FTS hits for query: {"field": "manages.reports", "match": "Hanna Drucilla"} is -1 (took 0.0ms)
      		 
      [2018-03-14 23:55:36,248] - [task:1334] INFO - ES hits for query: {"query": {"match": {"manages.reports": "Hanna Drucilla"}}} on es_index is 929 (took 25ms)
      		 
      [2018-03-14 23:55:36,248] - [task:1296] INFO - ----------------------------------------------------- Query # 2 ----------------------------------------------------
      		 
      [2018-03-14 23:55:36,268] - [rest_client:1971] INFO - Node 172.23.105.122 not part of cluster inactiveAdded
      		 
      [2018-03-14 23:55:36,269] - [fts_base:1075] ERROR - Error running query: No node in the cluster has 'fts' service enabled
      		 
      [2018-03-14 23:55:36,269] - [task:1300] INFO - Status: {}
      		 
      [2018-03-14 23:55:36,270] - [task:1324] INFO - FTS hits for query: {"field": "manages.reports", "match": "Solita Hanna Cytheria"} is -1 (took 0.0ms)
      		 
      [2018-03-14 23:55:36,374] - [task:1334] INFO - ES hits for query: {"query": {"match": {"manages.reports": "Solita Hanna Cytheria"}}} on es_index is 1349 (took 33ms)
      		 
      [2018-03-14 23:55:36,374] - [task:1296] INFO - ----------------------------------------------------- Query # 3 ----------------------------------------------------
      		 
      [2018-03-14 23:55:36,389] - [rest_client:1971] INFO - Node 172.23.105.122 not part of cluster inactiveAdded
      		 
      [2018-03-14 23:55:36,389] - [fts_base:1075] ERROR - Error running query: No node in the cluster has 'fts' service enabled
      		 
      [2018-03-14 23:55:36,390] - [task:1300] INFO - Status: {}
      		 
      [2018-03-14 23:55:36,390] - [task:1324] INFO - FTS hits for query: {"field": "dept", "match": "Training"} is -1 (took 0.0ms)
      		 
      [2018-03-14 23:55:36,463] - [task:1334] INFO - ES hits for query: {"query": {"match": {"dept": "Training"}}} on es_index is 947 (took 26ms)
      		 
      [2018-03-14 23:55:36,464] - [task:1296] INFO - ----------------------------------------------------- Query # 4 ----------------------------------------------------
      		 
      [2018-03-14 23:55:36,483] - [rest_client:1971] INFO - Node 172.23.105.122 not part of cluster inactiveAdded
      		 
      [2018-03-14 23:55:36,483] - [fts_base:1075] ERROR - Error running query: No node in the cluster has 'fts' service enabled
      		 
      [2018-03-14 23:55:36,483] - [task:1300] INFO - Status: {}
      		 
      [2018-03-14 23:55:36,484] - [task:1324] INFO - FTS hits for query: {"field": "type", "match": "wiki"} is -1 (took 0.0ms)
      		 
      [2018-03-14 23:55:36,488] - [task:1334] INFO - ES hits for query: {"query": {"match": {"type": "wiki"}}} on es_index is 0 (took 1ms)
      		 
      [2018-03-14 23:55:36,489] - [task:1296] INFO - ----------------------------------------------------- Query # 5 ----------------------------------------------------
      		 
      [2018-03-14 23:55:36,503] - [rest_client:1971] INFO - Node 172.23.105.122 not part of cluster inactiveAdded
      		 
      [2018-03-14 23:55:36,503] - [fts_base:1075] ERROR - Error running query: No node in the cluster has 'fts' service enabled
      		 
      [2018-03-14 23:55:36,503] - [task:1300] INFO - Status: {}
      		 
      [2018-03-14 23:55:36,504] - [task:1324] INFO - FTS hits for query: {"field": "email", "match": "fuscienne@mcdiabetes.com"} is -1 (took 0.0ms)
      		 
      [2018-03-14 23:55:37,115] - [task:1334] INFO - ES hits for query: {"query": {"match": {"email": "fuscienne@mcdiabetes.com"}}} on es_index is 10000 (took 206ms)
      		 
      [2018-03-14 23:55:37,117] - [task:1296] INFO - ----------------------------------------------------- Query # 6 ----------------------------------------------------
      		 
      [2018-03-14 23:55:37,131] - [rest_client:1971] INFO - Node 172.23.105.122 not part of cluster inactiveAdded
      		 
      [2018-03-14 23:55:37,132] - [fts_base:1075] ERROR - Error running query: No node in the cluster has 'fts' service enabled
      		 
      [2018-03-14 23:55:37,132] - [task:1300] INFO - Status: {}
      		 
      [2018-03-14 23:55:37,132] - [task:1324] INFO - FTS hits for query: {"field": "languages_known", "match": "Portuguese"} is -1 (took 0.0ms)
      		 
      [2018-03-14 23:55:37,244] - [task:1334] INFO - ES hits for query: {"query": {"match": {"languages_known": "Portuguese"}}} on es_index is 1388 (took 49ms)
      		 
      [2018-03-14 23:55:37,246] - [task:1296] INFO - ----------------------------------------------------- Query # 7 ----------------------------------------------------
      		 
      [2018-03-14 23:55:37,272] - [rest_client:1971] INFO - Node 172.23.105.122 not part of cluster inactiveAdded
      		 
      [2018-03-14 23:55:37,273] - [fts_base:1075] ERROR - Error running query: No node in the cluster has 'fts' service enabled
      		 
      [2018-03-14 23:55:37,273] - [task:1300] INFO - Status: {}
      		 
      [2018-03-14 23:55:37,273] - [task:1324] INFO - FTS hits for query: {"field": "type", "match": "wiki"} is -1 (took 0.0ms)
      		 
      [2018-03-14 23:55:37,279] - [task:1334] INFO - ES hits for query: {"query": {"match": {"type": "wiki"}}} on es_index is 0 (took 1ms)
      		 
      [2018-03-14 23:55:37,280] - [task:1296] INFO - ----------------------------------------------------- Query # 8 ----------------------------------------------------
      		 
      [2018-03-14 23:55:37,299] - [rest_client:1971] INFO - Node 172.23.105.122 not part of cluster inactiveAdded
      		 
      [2018-03-14 23:55:37,300] - [fts_base:1075] ERROR - Error running query: No node in the cluster has 'fts' service enabled
      		 
      [2018-03-14 23:55:37,300] - [task:1300] INFO - Status: {}
      		 
      [2018-03-14 23:55:37,301] - [task:1324] INFO - FTS hits for query: {"field": "name", "match": "Richardson IX"} is -1 (took 0.0ms)
      		 
      [2018-03-14 23:55:37,321] - [task:1334] INFO - ES hits for query: {"query": {"match": {"name": "Richardson IX"}}} on es_index is 158 (took 7ms)
      		 
      [2018-03-14 23:55:37,322] - [task:1296] INFO - ----------------------------------------------------- Query # 9 ----------------------------------------------------
      		 
      [2018-03-14 23:55:37,349] - [rest_client:1971] INFO - Node 172.23.105.122 not part of cluster inactiveAdded
      		 
      [2018-03-14 23:55:37,350] - [fts_base:1075] ERROR - Error running query: No node in the cluster has 'fts' service enabled
      		 
      [2018-03-14 23:55:37,350] - [task:1300] INFO - Status: {}
      		 
      [2018-03-14 23:55:37,351] - [task:1324] INFO - FTS hits for query: {"field": "languages_known", "match": "Japanese"} is -1 (took 0.0ms)
      		 
      [2018-03-14 23:55:37,449] - [task:1334] INFO - ES hits for query: {"query": {"match": {"languages_known": "Japanese"}}} on es_index is 1434 (took 43ms)
      		 
      [2018-03-14 23:55:37,449] - [task:1296] INFO - ----------------------------------------------------- Query # 10 ----------------------------------------------------
      		 
      [2018-03-14 23:55:37,471] - [fts_base:1991] INFO - Running query {"indexName": "default_index", "from": 0, "fields": [], "explain": false, "ctl": {"timeout": 60000, "consistency": {"vectors": {}, "level": ""}}, "query": {"field": "email", "match": "kory@mcdiabetes.com"}, "size": 10000000} on node: 172.23.105.122:
      		 
      [2018-03-14 23:55:37,481] - [rest_client:816] ERROR - socket error while connecting to http://172.23.105.122:8094/api/index/default_index/query error [Errno 111] Connection refused 
      [2018-03-14 23:55:40,888] - [task:1300] INFO - Status: {u'successful': 6, u'failed': 0, u'total': 6, u'errors': {}}
      		 
      [2018-03-14 23:55:40,889] - [task:1324] INFO - FTS hits for query: {"field": "email", "match": "kory@mcdiabetes.com"} is 10000 (took 46.370653ms)
      		 
      [2018-03-14 23:55:41,441] - [task:1334] INFO - ES hits for query: {"query": {"match": {"email": "kory@mcdiabetes.com"}}} on es_index is 10000 (took 195ms)
      		 
      [2018-03-14 23:55:41,450] - [task:1343] INFO - SUCCESS: Docs returned by FTS = docs returned by ES, doc_ids verified
      		 
      [2018-03-14 23:55:41,455] - [task:1296] INFO - ----------------------------------------------------- Query # 11 ----------------------------------------------------
      		 
      [2018-03-14 23:55:41,482] - [fts_base:1991] INFO - Running query {"indexName": "default_index", "from": 0, "fields": [], "explain": false, "ctl": {"timeout": 60000, "consistency": {"vectors": {}, "level": ""}}, "query": {"field": "dept", "match": "Accounts"}, "size": 10000000} on node: 172.23.105.122:
      		 
      [2018-03-14 23:55:41,519] - [task:1300] INFO - Status: {u'successful': 6, u'failed': 0, u'total': 6, u'errors': {}}
      		 
      [2018-03-14 23:55:41,520] - [task:1324] INFO - FTS hits for query: {"field": "dept", "match": "Accounts"} is 883 (took 4.469432ms)
      		 
      [2018-03-14 23:55:41,594] - [task:1334] INFO - ES hits for query: {"query": {"match": {"dept": "Accounts"}}} on es_index is 883 (took 23ms)
      		 
      [2018-03-14 23:55:41,595] - [task:1343] INFO - SUCCESS: Docs returned by FTS = docs returned by ES, doc_ids verified

      Attachments

        No reviews matched the request. Check your Options in the drop-down menu of this sections header.

        Activity

          People

            apiravi Aruna Piravi (Inactive)
            apiravi Aruna Piravi (Inactive)
            Votes:
            0 Vote for this issue
            Watchers:
            5 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Gerrit Reviews

                There are no open Gerrit changes

                PagerDuty