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

[FTS - Scorch toybuild2] Indexing gets stuck , err: unexpected end of JSON input

    XMLWordPrintable

Details

    • Untriaged
    • Centos 64-bit
    • Unknown

    Description

      Build
      5.5.0-1004 (Scorch toybuild#2)

      Testcase
      ./testrunner -p cluster=D+F -t fts.stable_topology_fts.StableTopFTS.test_query_type,items=100000,num_queries=1000,query_types=date_range,compare_es=True,GROUP=P1

      Steps
      1. Create a single node cluster with kv,fts services
      2. Load 100K emp dataset docs into default bucket, ES index
      3. Create default index, wait for all docs to get indexed ==> stuck at 29651
      4. Fire 1000 date-range queries against CB, ES and compare.

      QE bookkeeping: test#1 in defmap-P1 job

      2018-01-03 17:38:02 | INFO | MainProcess | test_thread | [fts_base.create] Creating fulltext-index default_index on 172.23.107.125
      		 
      2018-01-03 17:38:02 | INFO | MainProcess | test_thread | [rest_client.create_fts_index] {"params": {"store": {"mossStoreOptions": {}, "kvStoreName": "mossStore"}}, "name": "default_index", "planParams": {"numReplicas": 0, "maxPartitionsPerPIndex": 171}, "sourceName": "default", "sourceUUID": "", "sourceType": "couchbase", "type": "fulltext-index", "uuid": ""}
      		 
      2018-01-03 17:38:02 | INFO | MainProcess | test_thread | [rest_client.create_fts_index] Index default_index created
      		 
      2018-01-03 17:38:02 | INFO | MainProcess | test_thread | [fts_base.is_index_partitioned_balanced] Validating index distribution for default_index ...
      		 
      2018-01-03 17:38:02 | INFO | MainProcess | test_thread | [fts_base.is_index_partitioned_balanced] Validated: Number of PIndexes = 6
      		 
      2018-01-03 17:38:02 | INFO | MainProcess | test_thread | [fts_base.is_index_partitioned_balanced] Validated: Every pIndex serves 171 partitions or lesser
      		 
      2018-01-03 17:38:02 | INFO | MainProcess | test_thread | [fts_base.is_index_partitioned_balanced] Expecting num of partitions in each node in range 853-1024
      		 
      2018-01-03 17:38:02 | INFO | MainProcess | test_thread | [fts_base.is_index_partitioned_balanced] Validated: Node f4914b110b3c4073eca13dc37ab50024 houses 6 pindexes which serve 1024 partitions
      		 
      2018-01-03 17:38:03 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:38:03 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 0, docs in ES index: 100000 
      2018-01-03 17:38:09 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:38:09 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 7145, docs in ES index: 100000 
      2018-01-03 17:38:16 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:38:16 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 10577, docs in ES index: 100000 
      2018-01-03 17:38:22 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:38:22 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 13370, docs in ES index: 100000 
      2018-01-03 17:38:29 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:38:29 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 16375, docs in ES index: 100000 
      2018-01-03 17:38:35 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:38:36 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 21703, docs in ES index: 100000 
      2018-01-03 17:38:42 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:38:42 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 27117, docs in ES index: 100000 
      2018-01-03 17:38:49 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:38:49 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 34160, docs in ES index: 100000 
      2018-01-03 17:38:56 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:38:56 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 41492, docs in ES index: 100000 
      2018-01-03 17:39:03 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:39:03 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 49605, docs in ES index: 100000 
      2018-01-03 17:39:39 | ERROR | MainProcess | test_thread | [rest_client._http_request] socket error while connecting to http://172.23.107.125:8094/api/index/default_index/count error timed out 
      2018-01-03 17:39:39 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] unable to reach the host @ 172.23.107.125
      		 
      2018-01-03 17:40:16 | ERROR | MainProcess | test_thread | [rest_client._http_request] socket error while connecting to http://172.23.107.125:8094/api/index/default_index/count error timed out 
      2018-01-03 17:40:16 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] unable to reach the host @ 172.23.107.125
      		 
      2018-01-03 17:41:18 | ERROR | MainProcess | test_thread | [rest_client._http_request] socket error while connecting to http://172.23.107.125:8094/api/index/default_index/count error timed out 
      2018-01-03 17:41:18 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] unable to reach the host @ 172.23.107.125
      		 
      2018-01-03 17:42:05 | ERROR | MainProcess | test_thread | [rest_client._http_request] socket error while connecting to http://172.23.107.125:8094/api/index/default_index/count error timed out 
      2018-01-03 17:42:05 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] unable to reach the host @ 172.23.107.125
      		 
      2018-01-03 17:42:12 | ERROR | MainProcess | test_thread | [rest_client._http_request] socket error while connecting to http://172.23.107.125:8094/api/index/default_index/count error [Errno 104] Connection reset by peer 
      2018-01-03 17:42:15 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:42:15 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000 
      2018-01-03 17:42:21 | ERROR | MainProcess | test_thread | [rest_client._http_request] socket error while connecting to http://172.23.107.125:8091/nodes/self error [Errno 111] Connection refused 
      2018-01-03 17:42:24 | ERROR | MainProcess | test_thread | [rest_client._http_request] socket error while connecting to http://172.23.107.125:8091/nodes/self error [Errno 111] Connection refused 
      2018-01-03 17:42:27 | ERROR | MainProcess | test_thread | [rest_client._http_request] socket error while connecting to http://172.23.107.125:8091/nodes/self error [Errno 111] Connection refused 
      2018-01-03 17:42:30 | ERROR | MainProcess | test_thread | [rest_client._http_request] socket error while connecting to http://172.23.107.125:8091/nodes/self error [Errno 111] Connection refused 
      2018-01-03 17:42:33 | ERROR | MainProcess | test_thread | [rest_client._http_request] socket error while connecting to http://172.23.107.125:8091/nodes/self error [Errno 111] Connection refused 
      2018-01-03 17:42:36 | ERROR | MainProcess | test_thread | [rest_client._http_request] socket error while connecting to http://172.23.107.125:8091/nodes/self error [Errno 111] Connection refused 
      2018-01-03 17:42:39 | ERROR | MainProcess | test_thread | [rest_client._http_request] socket error while connecting to http://172.23.107.125:8094/api/index/default_index/count error [Errno 111] Connection refused 
      2018-01-03 17:42:42 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:42:42 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000 
      2018-01-03 17:42:48 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:42:48 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000 
      2018-01-03 17:42:55 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:42:55 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000 
      2018-01-03 17:43:01 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:43:01 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000 
      2018-01-03 17:43:07 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:43:07 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000 
      2018-01-03 17:43:13 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:43:13 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000 
      2018-01-03 17:43:19 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:43:19 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000 
      2018-01-03 17:43:26 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:43:26 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000 
      2018-01-03 17:43:32 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:43:32 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000 
      2018-01-03 17:43:38 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:43:38 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000 
      2018-01-03 17:43:44 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:43:44 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000 
      2018-01-03 17:43:50 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:43:50 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000 
      2018-01-03 17:43:56 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:43:56 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000 
      2018-01-03 17:44:02 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:44:03 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000 
      2018-01-03 17:44:09 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:44:09 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000 
      2018-01-03 17:44:15 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:44:15 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000 
      2018-01-03 17:44:21 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:44:21 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000 
      2018-01-03 17:44:27 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:44:27 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000 
      2018-01-03 17:44:33 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:44:33 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000 
      2018-01-03 17:44:39 | INFO | MainProcess | test_thread | [rest_client.fetch_bucket_stats] http://172.23.107.125:8091/pools/default/buckets/default/stats?zoom=minute
      		 
      2018-01-03 17:44:39 | INFO | MainProcess | test_thread | [fts_base.wait_for_indexing_complete] Docs in bucket = 100000, docs in FTS index 'default_index': 29651, docs in ES index: 100000

      Attaching logs from .125

      It appears that we keep seeing unexpected end of JSON input errors repeatedly for a very long time (includes failures from other tests).

      2018-01-03T17:42:13.125-08:00 [INFO] feed_dcp: OnError, name: default_index_1944dae781d9016e_18572d87: bucketName: default, bucketUUID: , err: sendStreamReq, err: unexpected end of JSON input
      		 
      2018-01-03T17:42:13.126-08:00 [INFO] main: meh.OnFeedError, srcType: couchbase, err: sendStreamReq, err: unexpected end of JSON input
      		 
      2018-01-03T17:42:13.160-08:00 [INFO] feed_dcp: OnError, name: default_index_1944dae781d9016e_54820232: bucketName: default, bucketUUID: , err: sendStreamReq, err: unexpected end of JSON input
      		 
      2018-01-03T17:42:13.162-08:00 [INFO] feed_dcp: OnError, name: default_index_1944dae781d9016e_aa574717: bucketName: default, bucketUUID: , err: sendStreamReq, err: unexpected end of JSON input
      		 
      :
      		 
      :
      		 
      2018-01-03T20:08:27.245-08:00 [INFO] feed_dcp: OnError, name: default_index_1944dae781d9016e_54820232: bucketName: default, bucketUUID: , err: sendStreamReq, err: unexpected end of JSON input

      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:
            2 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved:

              Gerrit Reviews

                There are no open Gerrit changes

                PagerDuty