Loading...

XML

Word

Printable

Details

Type: Bug
Resolution: Fixed
Priority: Critical
Fix Version/s: 5.5.0
Affects Version/s: 5.5.0
Component/s: fts
Labels:
- functional-test
- scorch

Triage:
Untriaged
Operating System:
Centos 64-bit
Is this a Regression?:
Yes

Description

Build
5.5.0-1676

Testcase
./testrunner -i /tmp/testexec.23490.ini cluster=D+F,get-cbcollect-info=True,GROUP=P0,index_type=scorch -t fts.stable_topology_fts.StableTopFTS.test_query_type,items=100000,num_queries=1000,query_types=match,cluster=D,F,F,compare_es=True,update=True,delete=True,GROUP=P0

On a deeper look at results from Scorch run, I'm seeing a case where deletes have not been propagated to the index on time(>3mins).

fts_ram_quota = 512mb

[2018-01-12 13:18:58,043] - [fts_base:876] INFO - Creating fulltext-index default_index on 172.23.105.171

[2018-01-12 13:18:58,043] - [rest_client:2607] INFO - {"params": {"store": {"mossStoreOptions": {}, "kvStoreName": "mossStore", "indexType": "scorch"}}, "name": "default_index", "planParams": {"numReplicas": 0, "maxPartitionsPerPIndex": 171}, "sourceName": "default", "sourceUUID": "", "sourceType": "couchbase", "type": "fulltext-index", "uuid": ""}

[2018-01-12 13:18:58,068] - [rest_client:2614] INFO - Index default_index created

[2018-01-12 13:18:58,069] - [fts_base:3481] INFO - Validating index distribution for default_index ...

[2018-01-12 13:18:58,085] - [fts_base:3377] INFO - sleep for 5 secs. No pindexes found, waiting for index to get created ...

[2018-01-12 13:19:03,207] - [fts_base:3499] INFO - Validated: Number of PIndexes = 6

[2018-01-12 13:19:03,214] - [fts_base:3511] INFO - Validated: Every pIndex serves 171 partitions or lesser

[2018-01-12 13:19:03,214] - [fts_base:3535] INFO - Expecting num of partitions in each node in range 853-1024

[2018-01-12 13:19:03,214] - [fts_base:3550] INFO - Validated: Node 083d40c120b712407ac1d52350d2e8c2 houses 6 pindexes which serve 1024 partitions

[2018-01-12 13:19:03,372] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:19:03,403] - [fts_base:3409] INFO - Docs in bucket = 100000, docs in FTS index 'default_index': 5256, docs in ES index: 100000

[2018-01-12 13:19:09,609] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:19:09,635] - [fts_base:3409] INFO - Docs in bucket = 100000, docs in FTS index 'default_index': 16872, docs in ES index: 100000

[2018-01-12 13:19:15,847] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:19:15,877] - [fts_base:3409] INFO - Docs in bucket = 100000, docs in FTS index 'default_index': 28096, docs in ES index: 100000

[2018-01-12 13:19:22,078] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:19:22,105] - [fts_base:3409] INFO - Docs in bucket = 100000, docs in FTS index 'default_index': 39786, docs in ES index: 100000

[2018-01-12 13:19:28,373] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:19:28,400] - [fts_base:3409] INFO - Docs in bucket = 100000, docs in FTS index 'default_index': 47497, docs in ES index: 100000

[2018-01-12 13:19:34,740] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:19:34,777] - [fts_base:3409] INFO - Docs in bucket = 100000, docs in FTS index 'default_index': 55698, docs in ES index: 100000

[2018-01-12 13:19:42,059] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:19:42,309] - [fts_base:3409] INFO - Docs in bucket = 100000, docs in FTS index 'default_index': 63245, docs in ES index: 100000

[2018-01-12 13:19:51,959] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:19:52,197] - [fts_base:3409] INFO - Docs in bucket = 100000, docs in FTS index 'default_index': 67694, docs in ES index: 100000

[2018-01-12 13:20:00,839] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:20:00,950] - [fts_base:3409] INFO - Docs in bucket = 100000, docs in FTS index 'default_index': 73552, docs in ES index: 100000

[2018-01-12 13:20:08,986] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:20:09,173] - [fts_base:3409] INFO - Docs in bucket = 100000, docs in FTS index 'default_index': 79651, docs in ES index: 100000

[2018-01-12 13:20:16,976] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:20:17,136] - [fts_base:3409] INFO - Docs in bucket = 100000, docs in FTS index 'default_index': 85179, docs in ES index: 100000

[2018-01-12 13:20:24,198] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:20:24,425] - [fts_base:3409] INFO - Docs in bucket = 100000, docs in FTS index 'default_index': 91781, docs in ES index: 100000

[2018-01-12 13:20:32,225] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:20:32,347] - [fts_base:3409] INFO - Docs in bucket = 100000, docs in FTS index 'default_index': 95775, docs in ES index: 100000

[2018-01-12 13:20:39,240] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:20:39,282] - [fts_base:3409] INFO - Docs in bucket = 100000, docs in FTS index 'default_index': 99379, docs in ES index: 100000

[2018-01-12 13:20:45,541] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:20:45,606] - [fts_base:3409] INFO - Docs in bucket = 100000, docs in FTS index 'default_index': 100000, docs in ES index: 100000

[2018-01-12 13:20:45,606] - [fts_base:3260] INFO - Updating keys @ C1 with expiry=0

[2018-01-12 13:20:55,973] - [task:1216] INFO - Starting operation 'update' on Elastic Search ...

[2018-01-12 13:20:57,962] - [task:1250] INFO - 5000 documents bulk loaded into ES

[2018-01-12 13:21:02,124] - [task:1250] INFO - 10000 documents bulk loaded into ES

[2018-01-12 13:21:03,388] - [data_helper:295] INFO - creating direct client 172.23.105.171:11210 default

[2018-01-12 13:21:06,607] - [task:1250] INFO - 15000 documents bulk loaded into ES

[2018-01-12 13:21:12,687] - [task:1250] INFO - 20000 documents bulk loaded into ES

[2018-01-12 13:21:22,053] - [task:1250] INFO - 25000 documents bulk loaded into ES

[2018-01-12 13:21:35,264] - [task:1250] INFO - 30000 documents bulk loaded into ES

[2018-01-12 13:21:35,348] - [task:1255] INFO - ES index count for 'es_index': 100000

[2018-01-12 13:21:35,354] - [fts_base:3297] INFO - Batched updates loaded to cluster(s)

[2018-01-12 13:21:35,354] - [fts_base:3302] INFO - Deleting keys @ C1

[2018-01-12 13:21:35,600] - [task:1216] INFO - Starting operation 'delete' on Elastic Search ...

[2018-01-12 13:21:35,861] - [data_helper:295] INFO - creating direct client 172.23.105.171:11210 default

[2018-01-12 13:21:36,882] - [task:1250] INFO - 5000 documents bulk loaded into ES

[2018-01-12 13:21:37,290] - [task:1250] INFO - 10000 documents bulk loaded into ES

[2018-01-12 13:21:37,821] - [task:1250] INFO - 15000 documents bulk loaded into ES

[2018-01-12 13:21:38,427] - [task:1250] INFO - 20000 documents bulk loaded into ES

[2018-01-12 13:21:39,079] - [task:1250] INFO - 25000 documents bulk loaded into ES

[2018-01-12 13:21:39,829] - [task:1250] INFO - 30000 documents bulk loaded into ES

[2018-01-12 13:21:39,842] - [task:1255] INFO - ES index count for 'es_index': 70000

[2018-01-12 13:21:52,961] - [fts_base:3322] INFO - Batched deletes sent to cluster(s)

[2018-01-12 13:21:53,067] - [fts_base:3377] INFO - sleep for 60 secs. Waiting for updates to get indexed... ...

[2018-01-12 13:22:53,529] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:22:53,609] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

[2018-01-12 13:23:00,205] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:23:00,256] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

[2018-01-12 13:23:07,318] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:23:07,355] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

[2018-01-12 13:23:14,333] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:23:14,384] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

[2018-01-12 13:23:21,385] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:23:21,448] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

[2018-01-12 13:23:28,055] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:23:28,115] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

[2018-01-12 13:23:34,744] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:23:34,785] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

[2018-01-12 13:23:42,383] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:23:42,425] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

[2018-01-12 13:23:49,016] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:23:49,061] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

[2018-01-12 13:23:55,377] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:23:55,432] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

[2018-01-12 13:24:02,944] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:24:02,999] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

[2018-01-12 13:24:10,750] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:24:10,944] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

[2018-01-12 13:24:18,331] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:24:18,384] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

[2018-01-12 13:24:24,969] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:24:25,015] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

[2018-01-12 13:24:32,295] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:24:32,366] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

[2018-01-12 13:24:38,702] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:24:38,736] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

[2018-01-12 13:24:45,354] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:24:45,398] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

[2018-01-12 13:24:51,746] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:24:51,794] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

[2018-01-12 13:24:59,279] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:24:59,319] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

[2018-01-12 13:25:06,171] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:25:06,204] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

[2018-01-12 13:25:12,458] - [rest_client:1875] INFO - http://172.23.105.171:8091/pools/default/buckets/default/stats?zoom=minute

[2018-01-12 13:25:12,500] - [fts_base:3409] INFO - Docs in bucket = 70000, docs in FTS index 'default_index': 100000, docs in ES index: 70000

Attaching cbcollect.

On .171, I see index count going down to 70000 eventually but after a while. The first reduced index count is recorded 8 mins after deletes are made -

2018-01-12T13:29:19.754-08:00 [INFO] stats: {

    "default:default_index:avg_queries_latency": 403.414855,

    "default:default_index:batch_merge_count": 0,

    "default:default_index:doc_count": 98112,

2018-01-12T13:34:19.496-08:00 [INFO] stats: {

    "default:default_index:avg_queries_latency": 386.784054,

    "default:default_index:batch_merge_count": 0,

    "default:default_index:doc_count": 70000

Attachments

- Sort By Name
- Sort By Date
- Ascending
- Descending
- Thumbnails
- List
- Download All

172.23.105.171-20180112-1354-diag.zip
7.62 MB
15/Jan/18 12:13 PM
172.23.97.219-20180115-1456-diag.zip
8.09 MB
15/Jan/18 8:50 PM

Gerrit Reviews

- Issue Only
- Show All Reviews
- Show Open Reviews
- Show All Issues
- Show Open Issues

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

Activity

People

Assignee:: Aruna Piravi (Inactive)

Reporter:: Aruna Piravi (Inactive)

Votes:: 0 Vote for this issue

Watchers:: 2 Start watching this issue

Dates

Created:: 15/Jan/18 12:13 PM

Updated:: 09/Apr/18 11:39 AM

Resolved:: 21/Mar/18 6:13 AM

Gerrit Reviews

There are no open Gerrit changes

[FTS-Scorch] Deletes take a while to get indexed

Details

Description

Attachments

Attachments

Gerrit Reviews

Activity

People

Dates

Gerrit Reviews

PagerDuty