N1QL: Intermittent issue: Using secondary index in a query for a particular case reports "Index not found" though index is present

This is not a regression but an intermittent issue.

Verified I see it in 4.5.1 also.

1. Run the following test which 

python testrunner.py -i query-tools.ini -c conf/tuq/py-tuq-dml-cbq.conf -p gsi_type=forestdb -p doc-per-day=1 -p standard_buckets=1 -p use_rest=False -p nodes_init=2 -p skip_cleanup=True

When you see the test executing inserts of 20 docs in a bucket as following:

 /opt/couchbase/bin//cbq  -engine=http://172.23.107.107:8091/ -q -s="INSERT into standard_bucket0 (key , value) VALUES (\"delete_wherequery-testemployee10682.8537702-0\", {'tasks_points': {'task1': 1, 'task2': 1}, 'name': 'employee-14', 'VMs': [{'RAM': 1, 'os': 'ubuntu', 'name': 'vm_1', 'memory': 1}, {'RAM': 1, 'os': 'windows', 'name': 'vm_2', 'memory': 1}], 'skills': ['skill2010', 'skill2011'], 'join_day': 14, 'test_rate': 1.1, 'join_mo': 1, 'join_yr': 2010, '_id': 'query-testemployee10682.8537702-0', 'email': '14-mail@couchbase.com', 'job_title': 'Engineer'})"

please go to step 2.

2. In another window try creating a secondary index and using it while the 20 items are being inserted through above test i.e.:

/opt/couchbase/bin//cbq  -engine=http://172.23.107.107:8091/ -q -s="CREATE INDEX idx_name ON default(name) USING GSI"

{

    "requestID": "b334eff4-2647-49f2-bcae-3e3315952a8b",

    "signature": null,

    "results": [

    ],

    "status": "success",

    "metrics": {

        "elapsedTime": "4.305776958s",

        "executionTime": "4.305664655s",

        "resultCount": 0,

        "resultSize": 0

    }

}

Verified that index got created, then try using it:

 /opt/couchbase/bin//cbq  -engine=http://172.23.107.107:8091/ -q -s="select name from default use index(idx_name using GSI)"

{

    "requestID": "fef4bcf3-a05f-4691-9a3f-58831d3845d0",

    "signature": {

        "name": "json"

    },

    "results": [

        {},

        {},

        {},

        {},

        {},

        {},

        {},

        {},

        {},

        {},

        {},

        {},

        {},

        {},

        {},

        {}

    ],

    "status": "success",

    "metrics": {

        "elapsedTime": "42.900638ms",

        "executionTime": "42.757274ms",

        "resultCount": 16,

        "resultSize": 32

    }

}

Above query gives correct results.

3. Issue the above query again:

/opt/couchbase/bin//cbq  -engine=http://172.23.107.107:8091/ -q -s="select name from default use index(idx_name using GSI)"

{

    "requestID": "c8e6e1b2-ce75-49e8-9527-cb06bda5f412",

    "errors": [

        {

            "code": 5000,

            "msg": "GSI index idx_name not found."

        }

    ],

    "status": "fatal",

    "metrics": {

        "elapsedTime": "2.387719ms",

        "executionTime": "2.271552ms",

        "resultCount": 0,

        "resultSize": 0,

        "errorCount": 1

    }

}

4. Issue the above query again:

/opt/couchbase/bin//cbq  -engine=http://172.23.107.107:8091/ -q -s="select name from default use index(idx_name using GSI)"

{

    "requestID": "c7a445c7-9044-4af9-85f9-5f1284fab7d3",

    "errors": [

        {

            "code": 5000,

            "msg": "GSI index idx_name not found."

        }

    ],

    "status": "fatal",

    "metrics": {

        "elapsedTime": "1.333141ms",

        "executionTime": "1.270263ms",

        "resultCount": 0,

        "resultSize": 0,

        "errorCount": 1

    }

}

5.Issue the above query again:

 /opt/couchbase/bin//cbq  -engine=http://172.23.107.107:8091/ -q -s="select name from default use index(idx_name using GSI)"

{

    "requestID": "dd48a2a9-db5f-463d-b663-dbbc1d4c33cf",

    "signature": {

        "name": "json"

    },

    "results": [

        {},

        {},

        {},

        {},

        {},

        {},

        {},

        {},

        {},

        {},

        {},

        {},

        {},

        {},

        {},

        {},

        {}

    ],

    "status": "success",

    "metrics": {

        "elapsedTime": "36.921947ms",

        "executionTime": "36.822565ms",

        "resultCount": 17,

        "resultSize": 34

    }

}

According to my analysis:

While the insertion of document was going on, the "use index" query gives incorrect result.

But I am not sure about exact point here.

Also if you try dropping the same index or recreating it using cbq, it gives correct msg:

 "errors": [

        {

            "code": 4300,

            "msg": "The index idx_name already exists."

        }

This test was run on a 2 node cluster. Here is an example ini:

global]

port:8091

username:root

password:couchbase

[servers]

#1:vm1

#2:vm2

1:vm1

2:vm2

[vm1]

ip:172.23.107.107

services:kv,index,n1ql

[vm2]

ip:172.23.106.244

services:kv,index,n1ql

[membase]

rest_username:Administrator

rest_password:password

[tuq_client]

goroot:/root/n1ql/go

gopath:/root/n1ql/gocode

Uploading logs from both nodes: cbcollect_172.23.107.107.zip  

and cbcollect_info172.23.106.244.zip 

Also uploading logs from failure of jenkins job: 172.23.106.244-20161218-0834-diag.zip  where the test which failed was:

./testrunner -i /tmp/n1ql_set3.ini -t tuqquery.tuq_dml.DMLQueryTests.update_keys_clause_hints,skip_load=True  -p doc-per-day=6 -p standard_buckets=1 -p use_rest=False -p nodes_init=2 

The reason was same as reported above.