CBIMPORT command returns success message, no documents show in bucket

Couchbase Server
1

I am running into a curious issue, I recently created a python to script to import JSON files using the following file format (windows and OSX respectively):

"D:\Program Files\Couchbase\Server\bin\cbimport.exe" json -c couchbase://127.0.0.1 -b Bucket -u USERNAME -p PASSWORD -f lines -g key::%PLAYER_ID% -l log.txt -d file://output/filename.json

/Applications/Couchbase\ Server.app/Contents/Resources/couchbase-core/bin/cbimport json -c couchbase://127.0.0.1 -b Bucket -u USERNAME -p PASSWORD -f lines -g key::%PLAYER_ID% -l log.txt -d file://output/filename.json

When I run that command in python using os.system() it returns the below message as well as showing up as having been successfully processed in the logging:

Json `file://output/filename.json` imported to `notLink/127.0.0.1:8091` successfully

Yet when I go to check out the documents in the bucket, none of the documents have been loaded. If I print the path I was executing with os.system() and run that myself from the command line, it shows an IDENTICAL success message and record in the logging, but actually shows up as a document in the bucket as well.

Here are the two records in the logging, for comparison:

Claims to work, doesn’t show up in the bucket:

2018-06-26T17:53:42.365-07:00 (Rest) GET notLink/127.0.0.1:8091/pools 200
2018-06-26T17:53:42.366-07:00 (Plan) Executing transfer plan
2018-06-26T17:53:42.366-07:00 (Plan) Checking for data movement restrictions between Bucket and Bucket
2018-06-26T17:53:42.366-07:00 (Plan) Transfering bucket configuration for Bucket to Bucket
2018-06-26T17:53:42.366-07:00 Unable to restore bucket settings, none exist
2018-06-26T17:53:42.366-07:00 (Plan) Transfering views definitions for Bucket to Bucket
2018-06-26T17:53:42.366-07:00 (Rest) GET notLink/127.0.0.1:8091/pools/default/nodeServices 200
2018-06-26T17:53:42.366-07:00 (Plan) Executing queries against Bucket to Bucket
2018-06-26T17:53:42.367-07:00 (Rest) GET notLink/127.0.0.1:8091/pools/default/nodeServices 200
2018-06-26T17:53:42.369-07:00 (Rest) GET notLink/127.0.0.1:8091/pools/default/buckets 200
2018-06-26T17:53:42.369-07:00 (Plan) Transfering full text index definitions for Bucket to Bucket
2018-06-26T17:53:42.369-07:00 (Plan) Deciding which key value data to transfer for Bucket
2018-06-26T17:53:42.369-07:00 (Plan) Transfering new key value data for Bucket to Bucket
2018-06-26T17:53:42.372-07:00 (Rest) GET notLink/127.0.0.1:8091/pools/default/buckets 200
2018-06-26T17:53:42.372-07:00 (Rest) GET notLink/127.0.0.1:8091/pools/default/nodeServices 200
2018-06-26T17:53:42.375-07:00 (Rest) GET notLink/127.0.0.1:8091/pools/default/buckets 200
2018-06-26T17:53:42.401-07:00 (Plan) Data transfer completed after 25.0668ms
2018-06-26T17:53:42.401-07:00 (Plan) Transfer of all data complete 
2018-06-26T17:53:42.401-07:00 (Plan) Transfer plan finished successfully

Worked, shows up in the bucket:

2018-06-26T18:07:45.919-07:00 (Rest) GET notLink/127.0.0.1:8091/pools 200
2018-06-26T18:07:45.920-07:00 (Plan) Executing transfer plan
2018-06-26T18:07:45.920-07:00 (Plan) Checking for data movement restrictions between Bucket and Bucket
2018-06-26T18:07:45.920-07:00 (Plan) Transfering bucket configuration for Bucket to Bucket
2018-06-26T18:07:45.920-07:00 Unable to restore bucket settings, none exist
2018-06-26T18:07:45.920-07:00 (Plan) Transfering views definitions for Bucket to Bucket
2018-06-26T18:07:45.920-07:00 (Rest) GET notLink/127.0.0.1:8091/pools/default/nodeServices 200
2018-06-26T18:07:45.920-07:00 (Plan) Executing queries against Bucket to Bucket
2018-06-26T18:07:45.921-07:00 (Rest) GET notLink/127.0.0.1:8091/pools/default/nodeServices 200
2018-06-26T18:07:45.923-07:00 (Rest) GET notLink/127.0.0.1:8091/pools/default/buckets 200
2018-06-26T18:07:45.923-07:00 (Plan) Transfering full text index definitions for Bucket to Bucket
2018-06-26T18:07:45.923-07:00 (Plan) Deciding which key value data to transfer for Bucket
2018-06-26T18:07:45.923-07:00 (Plan) Transfering new key value data for Bucket to Bucket
2018-06-26T18:07:45.925-07:00 (Rest) GET notLink/127.0.0.1:8091/pools/default/buckets 200
2018-06-26T18:07:45.926-07:00 (Rest) GET notLink/127.0.0.1:8091/pools/default/nodeServices 200
2018-06-26T18:07:45.929-07:00 (Rest) GET notLink/127.0.0.1:8091/pools/default/buckets 200
2018-06-26T18:07:45.955-07:00 (Plan) Data transfer completed after 25.0665ms
2018-06-26T18:07:45.955-07:00 (Plan) Transfer of all data complete 
2018-06-26T18:07:45.955-07:00 (Plan) Transfer plan finished successfully

I feel like I’m losing my mind. Anyone have any insight into why this might be happening?

Note: I changed all the URL prefixes since it wouldn’t let me post this with that many links.

2

Hi @stcarley. This is a complete guess, but is it possible Python’s os.system() is doing something weird (variable expansion or similar) to ‘key::%PLAYER_ID%’?

3

@graham.pople thanks for the suggestion. I have also tried splitting it up using shlex.split then running it via subprocess.run, with the exact same experience. I think my next attempt will be to construct a script using bash or powershell to do it and then automate that script.