gistfile1.txt

./testrunner -i INI_FILE.ini get-cbcollect-info=True,get-logs=False,stop-on-failure=False,cluster=D+F:F:F,GROUP=P0 -t fts.stable_topology_fts.StableTopFTS.test_match_all,items=10000,GROUP=P0

Test Input params:
{'logs_folder': '/data/workspace/cen006-p0-fts-vset00-01-stable-topology/logs/testrunner-16-Apr-07_11-19-18/test_23', 'GROUP': 'P0', 'items': '10000', 'conf_file': 'conf/fts/py-fts-simpletopology.conf', 'num_nodes': 3, 'cluster_name': 'INI_FILE', 'cluster': 'D+F:F:F', 'stop-on-failure': 'False', 'ini': 'INI_FILE.ini', 'case_number': 23, 'get-logs': 'False', 'get-cbcollect-info': 'True', 'spec': 'py-fts-simpletopology'}
[2016-04-07 13:04:51,333] - [fts_base:1913] INFO - ==== FTSbasetests setup is started for test #23 test_match_all ====
[2016-04-07 13:04:51,347] - [fts_base:902] INFO - removing nodes from cluster ...
[2016-04-07 13:04:51,360] - [fts_base:904] INFO - cleanup [ip:172.23.107.187 port:8091 ssh_username:root]
[2016-04-07 13:04:51,367] - [bucket_helper:137] INFO - deleting existing buckets [] on 172.23.107.187
[2016-04-07 13:04:51,389] - [cluster_helper:78] INFO - waiting for ns_server @ 172.23.107.187:8091
[2016-04-07 13:04:51,401] - [cluster_helper:80] INFO - ns_server @ 172.23.107.187:8091 is running
[2016-04-07 13:04:51,401] - [fts_base:852] INFO - Initializing Cluster ...
[2016-04-07 13:04:52,344] - [rest_client:811] INFO - pools/default params : memoryQuota=2069
[2016-04-07 13:04:52,351] - [rest_client:830] INFO - settings/indexes params : storageMode=forestdb
[2016-04-07 13:04:52,358] - [rest_client:774] INFO - settings/web params on 172.23.107.187:8091:username=Administrator&password=password&port=8091
[2016-04-07 13:04:52,375] - [fts_base:868] INFO - 172.23.107.145 will be configured with services fts
[2016-04-07 13:04:52,376] - [fts_base:868] INFO - 172.23.107.234 will be configured with services fts
[2016-04-07 13:04:53,376] - [task:404] INFO - adding node 172.23.107.145:8091 to cluster
[2016-04-07 13:04:53,377] - [rest_client:988] INFO - adding remote node @172.23.107.145:8091 to this cluster @172.23.107.187:8091
[2016-04-07 13:04:59,654] - [task:404] INFO - adding node 172.23.107.234:8091 to cluster
[2016-04-07 13:04:59,655] - [rest_client:988] INFO - adding remote node @172.23.107.234:8091 to this cluster @172.23.107.187:8091
[2016-04-07 13:05:07,931] - [rest_client:1206] INFO - rebalance params : password=password&ejectedNodes=&user=Administrator&knownNodes=ns_1%40172.23.107.187%2Cns_1%40172.23.107.145%2Cns_1%40172.23.107.234
[2016-04-07 13:05:07,943] - [rest_client:1210] INFO - rebalance operation started
[2016-04-07 13:05:07,949] - [rest_client:1338] INFO - rebalance percentage : 0.00 %
[2016-04-07 13:05:17,967] - [task:520] INFO - rebalancing was completed with progress: 100% in 10.0245139599 sec
[2016-04-07 13:05:18,989] - [rest_client:1772] INFO - http://172.23.107.187:8091/pools/default/buckets with param: bucketType=membase&evictionPolicy=valueOnly&threadsNumber=3&ramQuotaMB=1569&proxyPort=11211&authType=sasl&name=default&flushEnabled=1&replicaNumber=1&replicaIndex=1&saslPassword=None
[2016-04-07 13:05:18,998] - [rest_client:1794] INFO - 0.01 seconds to create bucket default
[2016-04-07 13:05:18,998] - [bucket_helper:305] INFO - waiting for memcached bucket : default in 172.23.107.187 to accept set ops
[2016-04-07 13:05:20,180] - [data_helper:295] INFO - creating direct client 172.23.107.187:11210 default
[2016-04-07 13:05:20,305] - [data_helper:295] INFO - creating direct client 172.23.107.187:11210 default
[2016-04-07 13:05:23,128] - [task:288] INFO - bucket 'default' was created with per node RAM quota: 1569
[2016-04-07 13:05:23,154] - [rest_client:1222] INFO - /diag/eval status on 172.23.107.187:8091: True content: "/opt/couchbase/var/lib/couchbase/logs" command: filename:absname(element(2, application:get_env(ns_server,error_logger_mf_dir))).
[2016-04-07 13:05:23,156] - [remote_util:169] INFO - connecting to 172.23.107.187 with username : root password : couchbase ssh_key: 
[2016-04-07 13:05:23,322] - [remote_util:203] INFO - Connected to 172.23.107.187
[2016-04-07 13:05:23,841] - [remote_util:2281] INFO - running command.raw on 172.23.107.187: zgrep "panic:" "/opt/couchbase/var/lib/couchbase/logs"/fts.log* | wc -l
[2016-04-07 13:05:23,942] - [remote_util:2318] INFO - command executed successfully
[2016-04-07 13:05:23,942] - [fts_base:2349] INFO - 0
[2016-04-07 13:05:23,942] - [remote_util:2281] INFO - running command.raw on 172.23.107.187: zgrep "SIGABRT: abort" "/opt/couchbase/var/lib/couchbase/logs"/fts.log* | wc -l
[2016-04-07 13:05:24,047] - [remote_util:2318] INFO - command executed successfully
[2016-04-07 13:05:24,048] - [fts_base:2349] INFO - 0
[2016-04-07 13:05:24,163] - [remote_util:169] INFO - connecting to 172.23.107.145 with username : root password : couchbase ssh_key: 
[2016-04-07 13:05:24,330] - [remote_util:203] INFO - Connected to 172.23.107.145
[2016-04-07 13:05:24,836] - [remote_util:2281] INFO - running command.raw on 172.23.107.145: zgrep "panic:" "/opt/couchbase/var/lib/couchbase/logs"/fts.log* | wc -l
[2016-04-07 13:05:24,908] - [remote_util:2318] INFO - command executed successfully
[2016-04-07 13:05:24,908] - [fts_base:2349] INFO - 0
[2016-04-07 13:05:24,908] - [remote_util:2281] INFO - running command.raw on 172.23.107.145: zgrep "SIGABRT: abort" "/opt/couchbase/var/lib/couchbase/logs"/fts.log* | wc -l
[2016-04-07 13:05:25,033] - [remote_util:2318] INFO - command executed successfully
[2016-04-07 13:05:25,034] - [fts_base:2349] INFO - 0
[2016-04-07 13:05:25,149] - [remote_util:169] INFO - connecting to 172.23.107.234 with username : root password : couchbase ssh_key: 
[2016-04-07 13:05:25,389] - [remote_util:203] INFO - Connected to 172.23.107.234
[2016-04-07 13:05:26,025] - [remote_util:2281] INFO - running command.raw on 172.23.107.234: zgrep "panic:" "/opt/couchbase/var/lib/couchbase/logs"/fts.log* | wc -l
[2016-04-07 13:05:26,142] - [remote_util:2318] INFO - command executed successfully
[2016-04-07 13:05:26,143] - [fts_base:2349] INFO - 0
[2016-04-07 13:05:26,144] - [remote_util:2281] INFO - running command.raw on 172.23.107.234: zgrep "SIGABRT: abort" "/opt/couchbase/var/lib/couchbase/logs"/fts.log* | wc -l
[2016-04-07 13:05:26,311] - [remote_util:2318] INFO - command executed successfully
[2016-04-07 13:05:26,312] - [fts_base:2349] INFO - 0
[2016-04-07 13:05:26,426] - [fts_base:2121] INFO - {'172.23.107.145': {'SIGABRT: abort': 0, 'panic:': 0}, '172.23.107.234': {'SIGABRT: abort': 0, 'panic:': 0}, '172.23.107.187': {'SIGABRT: abort': 0, 'panic:': 0}}
[2016-04-07 13:05:26,427] - [fts_base:1922] INFO - ==== FTSbasetests setup is finished for test #23 test_match_all ====
[2016-04-07 13:05:27,468] - [data_helper:295] INFO - creating direct client 172.23.107.187:11210 default
[2016-04-07 13:05:31,016] - [fts_base:2698] INFO - Loading phase complete!
[2016-04-07 13:05:31,040] - [fts_base:607] INFO - Checking if index already exists ...
[2016-04-07 13:05:31,091] - [rest_client:757] ERROR - http://172.23.107.234:8094/api/index/default_index_1 error 403 reason: status: 403, content: rest_auth: preparePerm, err: index not found 
 rest_auth: preparePerm, err: index not found 
[2016-04-07 13:05:31,094] - [rest_client:757] ERROR - http://172.23.107.234:8094/api/index/default_index_1 error 403 reason: status: 403, content: rest_auth: preparePerm, err: index not found 
 rest_auth: preparePerm, err: index not found 
[2016-04-07 13:05:31,094] - [fts_base:615] INFO - Creating fulltext-index default_index_1 on 172.23.107.234
[2016-04-07 13:05:31,094] - [rest_client:2074] INFO - {"params": {}, "name": "default_index_1", "planParams": {"hierarchyRules": null, "nodePlanParams": null, "numReplicas": 0, "planFrozen": false, "maxPartitionsPerPIndex": 32}, "sourceName": "default", "sourceUUID": "", "sourceType": "couchbase", "type": "fulltext-index", "sourceParams": {"authUser": "default", "dataManagerSleepMaxMS": 20000, "authSaslUser": "", "clusterManagerSleepMaxMS": 20000, "authSaslPassword": "", "clusterManagerSleepInitMS": 0, "dataManagerBackoffFactor": 0, "authPassword": "", "dataManagerSleepInitMS": 0, "feedBufferAckThreshold": 0, "feedBufferSizeBytes": 0, "clusterManagerBackoffFactor": 0}, "uuid": ""}
[2016-04-07 13:05:32,195] - [rest_client:2083] INFO - Index default_index_1 created
[2016-04-07 13:05:32,220] - [fts_base:2370] INFO - sleep for 5 secs. No pindexes found, waiting for index to get created ...
[2016-04-07 13:05:39,352] - [fts_base:2476] INFO - Validated: Number of PIndexes = 32
[2016-04-07 13:05:39,371] - [fts_base:2487] INFO - Validated: Every pIndex serves 32 partitions or lesser
[2016-04-07 13:05:39,371] - [fts_base:2503] INFO - Validated: pIndexes are distributed across [u'1ce9665b9057787061b9df34e1b219ce', u'ec57eced813721aaa6d5cc9eecfc2aea'] 
[2016-04-07 13:05:39,371] - [fts_base:2509] INFO - Expecting num of partitions in each node in range 480-544
[2016-04-07 13:05:39,371] - [fts_base:2524] INFO - Validated: Node 1ce9665b9057787061b9df34e1b219ce houses 16 pindexes which serve 512 partitions
[2016-04-07 13:05:39,372] - [fts_base:2524] INFO - Validated: Node ec57eced813721aaa6d5cc9eecfc2aea houses 16 pindexes which serve 512 partitions
[2016-04-07 13:05:40,071] - [fts_base:2392] INFO - Docs in bucket = 10000, docs in FTS index 'default_index_1': 2145
[2016-04-07 13:05:46,296] - [fts_base:2392] INFO - Docs in bucket = 10000, docs in FTS index 'default_index_1': 4331
[2016-04-07 13:05:51,637] - [fts_base:2392] INFO - Docs in bucket = 10000, docs in FTS index 'default_index_1': 6444
[2016-04-07 13:05:56,788] - [fts_base:2392] INFO - Docs in bucket = 10000, docs in FTS index 'default_index_1': 8479
[2016-04-07 13:06:02,041] - [fts_base:2392] INFO - Docs in bucket = 10000, docs in FTS index 'default_index_1': 9254
[2016-04-07 13:06:07,133] - [fts_base:2392] INFO - Docs in bucket = 10000, docs in FTS index 'default_index_1': 10000
[2016-04-07 13:06:12,230] - [fts_base:2392] INFO - Docs in bucket = 10000, docs in FTS index 'default_index_1': 10000
[2016-04-07 13:06:17,372] - [fts_base:2392] INFO - Docs in bucket = 10000, docs in FTS index 'default_index_1': 10000
[2016-04-07 13:06:22,507] - [fts_base:2392] INFO - Docs in bucket = 10000, docs in FTS index 'default_index_1': 10000
[2016-04-07 13:06:27,663] - [fts_base:2392] INFO - Docs in bucket = 10000, docs in FTS index 'default_index_1': 10000
[2016-04-07 13:06:32,775] - [fts_base:2392] INFO - Docs in bucket = 10000, docs in FTS index 'default_index_1': 10000
[2016-04-07 13:06:37,781] - [fts_base:2412] INFO - FTS indexed 10000 docs in 0.97 mins
[2016-04-07 13:06:37,903] - [fts_base:2618] INFO - Docs in index default_index_1=10000, bucket docs=10000
[2016-04-07 13:06:37,912] - [fts_base:1097] INFO - Running query {"from": 0, "indexName": "default_index_1", "fields": [], "explain": false, "ctl": {"timeout": 60000, "consistency": {"vectors": {}, "level": ""}}, "query": {"match_all": {}}, "size": 10000000} on node: 172.23.107.145
[2016-04-07 13:06:38,268] - [rest_client:757] ERROR - http://172.23.107.145:8094/api/index/default_index_1/query error 400 reason: status: 400, content: rest_index: Query, indexName: default_index_1, requestBody: {"from": 0, "indexName": "default_index_1", "fields": [], "explain": false, "ctl": {"timeout": 60000, "consistency": {"vectors": {}, "level": ""}}, "query": {"match_all": {}}, "size": 10000000}, req: &http.Request{Method:"POST", URL:(*url.URL)(0xc8203a4080), Proto:"HTTP/1.1", ProtoMajor:1, ProtoMinor:1, Header:http.Header{"Content-Length":[]string{"193"}, "Content-Type":[]string{"application/json"}, "Authorization":[]string{"Basic QWRtaW5pc3RyYXRvcjpwYXNzd29yZA=="}, "Accept":[]string{"*/*"}, "User-Agent":[]string{"Python-httplib2/$Rev: 259 $"}, "Accept-Encoding":[]string{"identity"}}, Body:(*http.body)(0xc82260d5c0), ContentLength:193, TransferEncoding:[]string(nil), Close:false, Host:"172.23.107.145:8094", Form:url.Values{}, PostForm:url.Values{}, MultipartForm:(*multipart.Form)(nil), Trailer:http.Header(nil), RemoteAddr:"172.23.107.140:60354", RequestURI:"/api/index/default_index_1/query", TLS:(*tls.ConnectionState)(nil), Cancel:(<-chan struct {})(nil)}, err: bleve: QueryBlevePIndexImpl remote client returned status: 400 body: rest_index: QueryPIndex, pindexName: default_index_1_62211a241d144f2f_9e13fa43, requestBody: {"ctl":{"timeout":59496,"consistency":{"level":"","vectors":{}}},"query":{"boost":1},"size":10000000,"from":0,"highlight":null,"fields":[],"facets":null,"explain":false}, req: &http.Request{Method:"POST", URL:(*url.URL)(0xc820261580), Proto:"HTTP/1.1", ProtoMajor:1, ProtoMinor:1, Header:http.Header{"User-Agent":[]string{"Go-http-client/1.1"}, "Content-Length":[]string{"169"}, "Authorization":[]string{"Basic QGZ0cy1jYmF1dGg6YjJiMTdhZjk3NWM1ZWNiZGM2YzhhZTBkMzQ0OWQxZWI="}, "Content-Type":[]string{"application/json"}, "Accept-Encoding":[]string{"gzip"}}, Body:(*http.body)(0xc8224929c0), ContentLength:169, TransferEncoding:[]string(nil), Close:false, Host:"172.23.107.234:8094", Form:url.Values{}, PostForm:url.Values{}, MultipartForm:(*multipart.Form)(nil), Trailer:http.Header(nil), RemoteAddr:"172.23.107.145:46354", RequestURI:"/api/pindex/default_index_1_62211a241d144f2f_9e13fa43/query", TLS:(*tls.ConnectionState)(nil), Cancel:(<-chan struct {})(nil)}, err: bleve: BleveDest.Query parsing searchRequest, req: {"ctl":{"timeout":59496,"consistency":{"level":"","vectors":{}}},"query":{"boost":1},"size":10000000,"from":0,"highlight":null,"fields":[],"facets":null,"explain":false}, err: unknown query type