Longpoll changes request with limit and active_only fails to return results

[ketodiet]

Sync Gateway version

Couchbase Sync Gateway/1.3.1(16;f18e833)

Operating system

Windows 10

Config file

{
"interface": ":4984",
"adminInterface": ":4985",
"log": ["CRUD", "REST+", "Access"],
"databases": {
"ketodiet": {
"server": "http://localhost:8091",
"bucket": "ketodiet",
"sync": function(doc, oldDoc) { if (!doc.syncUserId) { throw({forbidden: "Missing user ID"}); } channel(doc.syncUserId); }
}
}
}

Log output

N/A - see desciption

Expected behavior

The actual sequence Id is: 21995. When listening for changes using the GET /{db}/_changes Admin API, I would expect to read up that sequence number. When the limit parameter is not used it works fine. When I specify limit=100 in the request then the API returns up to 20923 and then stops. When the limit parameter is not used, it works fine.

Here's the ADMIN request:
2017-01-22T20:07:17.550Z HTTP: #3: GET /ketodiet/_changes?style=all_docs&active_only=true&include_docs=true&feed=longpoll&limit=100&since=20923 (ADMIN)

And this is the last update:
2017-01-22T19:59:38.098Z HTTP: #2: POST /ketodiet/_changes?feed=longpoll&heartbeat=300000&style=all_docs&since=21995 (as 3)

Actual behavior

When limit is used, the _changes API doesn't keep up with the actual changes.

Steps to reproduce

1. Use the _changes Admin API without specifying a limit (see above for parameters used)
2. You'll received all changes as expected
3. Add limit=x (I used 100, i.e. limit=100)
4. Repeat 1 & 2 with limit and you'll find that the latest changes are be returned

[adamcfraser]

@ketodiet I'm not sure I completely understand the problem as described. If your changes request would have more than 100 entries, then it's correct for the changes result to not return all results when you specify limit=100.

Are you saying that when you execute a longpoll changes request with limit=100, you're receiving less than 100 entries in the response, and not getting all the expected results?

[ketodiet]

@adamcfraser what happens when I use limit=100, is that I correctly receive results in batches of 100, till I get near the latest sequence Id (20923 out of 21995) and then the updates stop coming in. The longpoll request on 20923 is waiting for ever and only receives heartbeats instead of changes:

2017-01-22T20:07:17.550Z HTTP: #3: GET /ketodiet/_changes?style=all_docs&active_only=true&include_docs=true&feed=longpoll&limit=100&since=20923 (ADMIN)

If I remove the limit param everything works as expected but then of course I cannot throttle the rate by which I process changes.

By the way, I also tried the POST API passing the params as a json object and experience the same issue.

[adamcfraser]

@ketodiet That's very odd. If possible, can you provide the following in a gist (scrubbed if necessary):

1. Sync Gateway logs and changes response when running without limit
2. Sync Gateway logs and changes response when running with limit=100, since=20923

[ketodiet]

@adamcfraser sure - any specific flags you want me to use for the logs? I current use: "log": ["CRUD", "REST+", "Access"]. Thanks.

[adamcfraser]

Include Changes+ as well. Thanks!

[ketodiet]

@adamcfraser here's the SG log with no limit (since=20923):
https://gist.github.com/ketodiet/d0cd49ed0d44aeeb92baa18621b17faf

here's the SG log with limit=100 (since=20923)
https://gist.github.com/ketodiet/23a7b030ef64268a453edea6923981e9

(In both cases I use a timeout value of 5000ms - This doesn't really make any difference, I added it later on.)

[adamcfraser]

@ketodiet In the limit case, it doesn't look like you're correctly updating the since value on subsequent requests (every request shows since=20923, and is returning the same 100 results).

From the logs I can't see what's being returned as last_seq in the previous request, but that's what you should be using for subsequent requests. If you're already using that, can you provide a sample changes response with limit?

[ketodiet]

@adamcfraser the request with since=20923 & limit=100 returns:

{"results":[
],
"last_seq":"20923"}

which I confirmed with a network capture. So basically, it returns the same sequence id and no results.

If it helps I can do a network capture.

Edit: I'm wondering if the method is skipping records (maybe deleted or whatever) but still counts them ending up with an empty result set. Just a thought.

[adamcfraser]

I'm wondering whether this is an issue with the use of ActiveOnly - do you see the same results if you exclude active_only=true from the limit requests?

[ketodiet]

@adamcfraser yes that's it. Works fine when active_only is set to false.

[adamcfraser]

It sounds like when using limit=x and active_only=true, in the scenario where the first x results found by the changes feed are not active, the changes processing loop is going into wait mode, instead of iterating and returning more results.

[ketodiet]

yes I agree - thank you for your help. It's easy to work round this issue.