Strange NotFoundError while using n1ql_index_build_deferred()

Hello! I’m using the Python SDK to create some indices and during script execution I get the following without fail:

Traceback (most recent call last):
  File "manage_indexes.py", line 112, in <module>
    main(args.operation, args.environment, bucket_pw)
  File "manage_indexes.py", line 99, in main
    create_indexes(cluster, node, bucket_passwd)
  File "manage_indexes.py", line 48, in create_indexes
    create_index(bucket, node, app)
  File "manage_indexes.py", line 75, in create_index
    bucket_mgr.n1ql_index_build_deferred()
  File "/Users/mmorri929/venvs/couchbase/lib/python2.7/site-packages/couchbase/bucketmanager.py", line 497, in n1ql_index_build_deferred
    return IxmgmtRequest(self._cb, 'build', info).execute()
  File "/Users/mmorri929/venvs/couchbase/lib/python2.7/site-packages/couchbase/_ixmgmt.py", line 160, in execute
    return [x for x in self]
  File "/Users/mmorri929/venvs/couchbase/lib/python2.7/site-packages/couchbase/_ixmgmt.py", line 147, in __iter__
    raw_rows = self.__raw.fetch(self._mres)
couchbase.exceptions._NotFoundError_0xD (generated, catch NotFoundError): <RC=0xD[The key does not exist on the server], HTTP Request failed. Examine 'objextra' for full result, Results=1, C Source=(src/http.c,144), OBJ=ViewResult<rc=0xD[The key does not exist on the server], value={u'status': u'success', u'metrics': {u'elapsedTime': u'446.002501ms', u'executionTime': u'445.930043ms', u'resultSize': 353, u'resultCount': 1, u'sortCount': 1}, u'results': [], u'requestID': u'6d03c245-de2b-4c21-b832-8fe43568bc7c', u'signature': {u'*': u'*'}}, http_status=200>>

The strange part about this is that some of the indices are created fine and I cannot, for the life of me, figoure what what key it’s talking about that might be missing. Examining objextra as the message suggest yields the following message which I can’t really glean anything from either:

ViewResult<rc=0xD[The key does not exist on the server], value={u'status': u'success', u'metrics': {u'elapsedTime': u'423.019003ms', u'executionTime': u'422.95924ms', u'resultSize': 1378, u'resultCount': 4, u'sortCount': 4}, u'results': [], u'requestID': u'ac04380b-861f-431f-9000-eb096665b702', u'signature': {u'*': u'*'}}, http_status=200>

Does anyone have any idea what this could be or what additional steps I can add to help troubleshoot what is causing this issue?

Hi Matthew,

The error doesn’t seem to mention a specific key - I guess that information could have been lost in aggregating the results of index creation.

If you set LCB_LOGLEVEL=5 in your environment variables and, just prior to your index call, add:
couchbase.enable_logging()

Do you get any more information?

Thanks,

Ellis

Hey Ellis!

Thanks for getting back to me. There is additional output but it doesn’t really provide any additional insight - at least none that I can glean. It looks like the “key” in this case might be idx.* but all indications point to it being fetched successfully. Any other thoughts? Am I missing something here?

1289ms [I142c588a] {86863/307} [DEBUG] (ixmgmt - L:185) (mgreq=0x7ff5cf9051f0) Issuing query {"statement":"SELECT idx.* FROM system:indexes idx WHERE keyspace_id=\"mgmt-api\" AND true ORDER BY is_primary DESC, name ASC"}
1289ms [I142c588a] {86863/307} [TRACE] (http-io - L:249) <host:8093> POST  http://host:8093/query/service. Body=151 bytes
1289ms [I142c588a] {86863/307} [DEBUG] (lcbio_mgr - L:448) <host:8093> (HE=0x7ff5cf920e90) Creating new connection because none are available in the pool
1289ms [I142c588a] {86863/307} [TRACE] (lcbio_mgr - L:359) <host:8093> (HE=0x7ff5cf920e90) New pool entry: I=0x7ff5cf921510
1289ms [I142c588a] {86863/307} [INFO] (connection - L:474) <host:8093> (SOCK=7af3d4a929af0fa4) Starting. Timeout=75000000us
1290ms [I142c588a] {86863/307} [DEBUG] (connection - L:238) <host:8093> (SOCK=7af3d4a929af0fa4) Created new socket with FD=11
1290ms [I142c588a] {86863/307} [TRACE] (connection - L:339) <host:8093> (SOCK=7af3d4a929af0fa4) Scheduling I/O watcher for asynchronous connection completion.
1334ms [I142c588a] {86863/307} [INFO] (connection - L:147) <host:8093> (SOCK=7af3d4a929af0fa4) Connected established
1334ms [I142c588a] {86863/307} [DEBUG] (connection - L:106) <host:8093> (SOCK=7af3d4a929af0fa4) Successfully set TCP_NODELAY
1334ms [I142c588a] {86863/307} [DEBUG] (connection - L:106) <host:8093> (SOCK=7af3d4a929af0fa4) Successfully set TCP_KEEPALIVE
1334ms [I142c588a] {86863/307} [DEBUG] (lcbio_mgr - L:318) <host:8093> (HE=0x7ff5cf920e90) Received result for I=0x7ff5cf921510,C=0x0; E=0x0
1334ms [I142c588a] {86863/307} [DEBUG] (lcbio_mgr - L:278) <host:8093> (HE=0x7ff5cf920e90) Assigning R=0x7ff5cf921190 SOCKET=0x7ff5cf920d50
1334ms [I142c588a] {86863/307} [DEBUG] (ioctx - L:101) <host:8093> (CTX=0x7ff5cf920b80,unknown) Pairing with SOCK=7af3d4a929af0fa4
1382ms [I142c588a] {86863/307} [DEBUG] (ioctx - L:151) <host:11210> (CTX=0x7ff5ce50c3d0,sasl) Destroying context. Pending Writes=0, Entered=true, Socket Refcount=1
1382ms [I142c588a] {86863/307} [DEBUG] (ioctx - L:101) <host:11210> (CTX=0x7ff5cf921650,unknown) Pairing with SOCK=0a39c860f6f68994
1425ms [I142c588a] {86863/307} [TRACE] (confmon - L:152) Not applying configuration received via CCCP. No changes detected. A.rev=22692, B.rev=22689
1972ms [I142c588a] {86863/307} [DEBUG] (ioctx - L:151) <host:8093> (CTX=0x7ff5cf920b80,mgmt/capi) Destroying context. Pending Writes=0, Entered=true, Socket Refcount=1
1972ms [I142c588a] {86863/307} [INFO] (lcbio_mgr - L:498) <host:8093> (HE=0x7ff5cf920e90) Placing socket back into the pool. I=0x7ff5cf921510,C=0x7ff5cf920d50
Traceback (most recent call last):
  File "manage_indexes.py", line 115, in <module>
    main(args.operation, args.environment, bucket_pw)
  File "manage_indexes.py", line 102, in main
    create_indexes(cluster, node, bucket_passwd)
  File "manage_indexes.py", line 50, in create_indexes
    create_index(bucket, node, app)
  File "manage_indexes.py", line 78, in create_index
    bucket_mgr.n1ql_index_build_deferred()
  File "/Users/mmorri929/venvs/couchbase/lib/python2.7/site-packages/couchbase/bucketmanager.py", line 497, in n1ql_index_build_deferred
    return IxmgmtRequest(self._cb, 'build', info).execute()
  File "/Users/mmorri929/venvs/couchbase/lib/python2.7/site-packages/couchbase/_ixmgmt.py", line 160, in execute
    return [x for x in self]
  File "/Users/mmorri929/venvs/couchbase/lib/python2.7/site-packages/couchbase/_ixmgmt.py", line 147, in __iter__
    raw_rows = self.__raw.fetch(self._mres)
couchbase.exceptions._NotFoundError_0xD (generated, catch NotFoundError): <RC=0xD[The key does not exist on the server], HTTP Request failed. Examine 'objextra' for full result, Results=1, C Source=(src/http.c,144), OBJ=ViewResult<rc=0xD[The key does not exist on the server], value={u'status': u'success', u'metrics': {u'elapsedTime': u'590.414977ms', u'executionTime': u'590.198483ms', u'resultSize': 1723, u'resultCount': 5, u'sortCount': 5}, u'results': [], u'requestID': u'400a1178-1697-4fc2-b887-62f0c18337ee', u'signature': {u'*': u'*'}}, http_status=200>>