googleapis/python-datastore

Bug querying with offset

jacobg opened this issue · 16 comments

jacobg commented

Sorry I don't have a good repro for you because I'm only repro-ing it on my data, but here is a code that seems to clearly demonstrate a bug:

import time

from google.cloud import datastore


def _create_query(ds_client: datastore.Client) -> datastore.Query:
    query = ds_client.query(kind='my-kind')
    query.add_filter(filter=datastore.query.PropertyFilter('active', '=', True))
    query.add_filter(filter=datastore.query.PropertyFilter('account', '=', 111))
    query.add_filter(filter=datastore.query.PropertyFilter('roles', '=', 'w'))
    query.add_filter(filter=datastore.query.PropertyFilter('labels', '=', 222))
    return query


def run():
    ds_client = datastore.Client(project='my-project')

    start = time.time()
    count = 0
    for entity in _create_query(ds_client).fetch():
        count += 1
    end = time.time()
    print(f'Fetched all {count} entities in {end - start} seconds')
    real_count = count

    for offset in range(0, real_count + 2):
        start = time.time()
        count = 0
        for entity in _create_query(ds_client).fetch(offset=offset):
            count += 1
        end = time.time()
        print(f'Fetched at offset={offset} {count} entities in {end - start} seconds')


if __name__ == '__main__':
    run()

In addition, I added two print statements in google/cloud/datastore/query.py's _next_page while loop:

        while (
            response_pb.batch.more_results == _NOT_FINISHED
            and response_pb.batch.skipped_results < query_pb.offset
        ):
            # We haven't finished processing. A likely reason is we haven't
            # skipped all of the results yet. Don't return any results.
            # Instead, rerun query, adjusting offsets. Datastore doesn't process
            # more than 1000 skipped results in a query.
            old_query_pb = query_pb
            query_pb = query_pb2.Query()
            query_pb._pb.CopyFrom(old_query_pb._pb)  # copy for testability
            query_pb.start_cursor = response_pb.batch.skipped_cursor
            query_pb.offset -= response_pb.batch.skipped_results
            print(f'response_pb.batch.skipped_cursor = {response_pb.batch.skipped_cursor}')
            print(f'response_pb.batch.skipped_results = {response_pb.batch.skipped_results}')

            request = {
                "project_id": self._query.project,
                "partition_id": partition_id,
                "read_options": read_options,
                "query": query_pb,
            }
            helpers.set_database_id_to_request(request, self.client.database)

            response_pb = self.client._datastore_api.run_query(
                request=request,
                **kwargs,
            )

This is the output running the script:

Fetched all 16 entities in 1.7923529148101807 seconds
Fetched at offset=0 16 entities in 1.6426568031311035 seconds
Fetched at offset=1 15 entities in 1.7998042106628418 seconds
Fetched at offset=2 14 entities in 1.525015115737915 seconds
Fetched at offset=3 13 entities in 1.4684479236602783 seconds
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xdb\x81\x83\x8c\xb5\x91\xe4\x03\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
Fetched at offset=4 12 entities in 1.6105940341949463 seconds
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xdb\x81\x83\x8c\xb5\x91\xe4\x03\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
Fetched at offset=5 11 entities in 1.4919788837432861 seconds
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xdb\x81\x83\x8c\xb5\x91\xe4\x03\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
Fetched at offset=6 10 entities in 1.6434409618377686 seconds
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xdb\x81\x83\x8c\xb5\x91\xe4\x03\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xcd\x9e\x8d\xc1\xf7\xb4\xcf\x06\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
Fetched at offset=7 9 entities in 1.6705551147460938 seconds
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xdb\x81\x83\x8c\xb5\x91\xe4\x03\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xcd\x9e\x8d\xc1\xf7\xb4\xcf\x06\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
Fetched at offset=8 8 entities in 1.490036964416504 seconds
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xdb\x81\x83\x8c\xb5\x91\xe4\x03\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xcd\x9e\x8d\xc1\xf7\xb4\xcf\x06\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
Fetched at offset=9 7 entities in 1.263127088546753 seconds
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xdb\x81\x83\x8c\xb5\x91\xe4\x03\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xcd\x9e\x8d\xc1\xf7\xb4\xcf\x06\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xde\xf1\xc5\x9c\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
Fetched at offset=10 6 entities in 1.1788661479949951 seconds
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xdb\x81\x83\x8c\xb5\x91\xe4\x03\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xcd\x9e\x8d\xc1\xf7\xb4\xcf\x06\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xde\xf1\xc5\x9c\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xda\xc7\xf2\xf9\xab\xbe\xab\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 1
Fetched at offset=11 5 entities in 1.3047678470611572 seconds
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xdb\x81\x83\x8c\xb5\x91\xe4\x03\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xcd\x9e\x8d\xc1\xf7\xb4\xcf\x06\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xde\xf1\xc5\x9c\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xda\xc7\xf2\xf9\xab\xbe\xab\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 1
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xde\xf1\xc5\xdc\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 1
Fetched at offset=12 4 entities in 1.4790778160095215 seconds
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xdb\x81\x83\x8c\xb5\x91\xe4\x03\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xcd\x9e\x8d\xc1\xf7\xb4\xcf\x06\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xde\xf1\xc5\x9c\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xda\xc7\xf2\xf9\xab\xbe\xab\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 1
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xde\xf1\xc5\xdc\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 1
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xb4\xa6\x81\xd3\x84\xc7\x88\t\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 1
response_pb.batch.skipped_cursor = b''
response_pb.batch.skipped_results = 0
Fetched at offset=13 15 entities in 2.0598793029785156 seconds
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xdb\x81\x83\x8c\xb5\x91\xe4\x03\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xcd\x9e\x8d\xc1\xf7\xb4\xcf\x06\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xde\xf1\xc5\x9c\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xda\xc7\xf2\xf9\xab\xbe\xab\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 1
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xde\xf1\xc5\xdc\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 1
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xb4\xa6\x81\xd3\x84\xc7\x88\t\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 1
response_pb.batch.skipped_cursor = b''
response_pb.batch.skipped_results = 0
Fetched at offset=14 14 entities in 2.045603036880493 seconds
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xdb\x81\x83\x8c\xb5\x91\xe4\x03\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xcd\x9e\x8d\xc1\xf7\xb4\xcf\x06\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xde\xf1\xc5\x9c\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xda\xc7\xf2\xf9\xab\xbe\xab\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 1
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xde\xf1\xc5\xdc\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 1
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xb4\xa6\x81\xd3\x84\xc7\x88\t\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 1
response_pb.batch.skipped_cursor = b''
response_pb.batch.skipped_results = 0
Fetched at offset=15 13 entities in 2.3071401119232178 seconds
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xdb\x81\x83\x8c\xb5\x91\xe4\x03\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xcd\x9e\x8d\xc1\xf7\xb4\xcf\x06\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xde\xf1\xc5\x9c\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xda\xc7\xf2\xf9\xab\xbe\xab\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 1
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xde\xf1\xc5\xdc\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 1
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xb4\xa6\x81\xd3\x84\xc7\x88\t\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 1
response_pb.batch.skipped_cursor = b''
response_pb.batch.skipped_results = 0
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xdb\x81\x83\x8c\xb5\x91\xe4\x03\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
Fetched at offset=16 12 entities in 2.1022279262542725 seconds
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xdb\x81\x83\x8c\xb5\x91\xe4\x03\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xcd\x9e\x8d\xc1\xf7\xb4\xcf\x06\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xde\xf1\xc5\x9c\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xda\xc7\xf2\xf9\xab\xbe\xab\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 1
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xde\xf1\xc5\xdc\x08\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 1
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xb4\xa6\x81\xd3\x84\xc7\x88\t\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 1
response_pb.batch.skipped_cursor = b''
response_pb.batch.skipped_results = 0
response_pb.batch.skipped_cursor = b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xdb\x81\x83\x8c\xb5\x91\xe4\x03\x0c\x18\x00 \x00'
response_pb.batch.skipped_results = 3
Fetched at offset=17 11 entities in 1.9469151496887207 seconds

It seems what happens is that if the while loop that skips results based on offset reaches the end of the actual resultset, then the response returns empty cursor. In that case, what the code should do is realize there are no results and immediately return. However, what the code does instead is move on to run the full query again for one more iteration, then exit the while loop, and fetch and return all the remaining results.

Am I understanding that correctly?

jacobg commented

Actually, maybe the backend is returning no cursor and 0 skipped results before it got through all the results it needs to offset.

It seems to repro when querying on multiple properties, with at least one of them being a list property. It seems to work correctly, if not querying any list property, or if only querying on one list property and nothing else.

Could that mean a backend bug, possibly when querying a list with an offset using zig-zag merge?

daniel-sanche commented

Hey Jacob, just to make sure I'm understanding this right:

  • the bug starts in your log at Fetched at offset=13 15 entities, because we'd expect offset+number returned to equal 16. All the previous lines do, but 13 and higher don't.
  • You only see this issue when querying against multiple properties, at least one of which is a list
    Is that right?

How did you encounter this bug in your real code? Were you just seeing more results than you were expecting when passing in an offset value?

I can try to build a test case that reproduces this, just want to make sure I'm understanding it first

jacobg commented

Hi @daniel-sanche , Thanks for the reply.

  1. Yes, your explanation of the offset issue is correct.
  2. Yes, it seems to only occur with a list property and an additional property, when used with offset.

This bug was seen on live data in our project. I wrote a script to create a new kind with some similar form of data, but the bug did not reproduce. It seems to suggest that perhaps it requires a larger amount of data that is not returned in the query in order to expose the bug. My thinking is maybe it has to do with zig-zag merge along with offsets?

I also filed Google Cloud Support case # 52190476. Since you work for Google, I can send you the specific project id, kind, and filter property names that have this issue.

daniel-sanche commented

Ok, interesting. Yeah I just tried to write a system test to reproduce it, but nothing is showing up there. But we do have very limited data in that test project.

I'll keep trying to reproduce, but if you have bandwidth to help narrow it down:

  1. If you can help find a minimal reproducible sample, that would help a lot
  2. If you're comfortable working with protos, another thing you could try is re-writing your sample to target the autogenerated protobuf API directly. This should tell us if the bug is in the backend, or somewhere in the hand-written library code.
  3. Adding some logs into that same protobuf client could also give us some hints about what's going on. It could be useful to print all the request protos there before they're sent, and/or the responses returned
jacobg commented

Hi @daniel-sanche,

I just realized the GCP Console allows GQL queries with an OFFSET, so I tested there, and it produces the correct result! So maybe this is a python-datastore bug?

I posted the test details onto the GCP Support ticket.

jacobg commented

Here is the same test written node.js and it returns the correct result. So this really looks like a python-datastore bug.

const {Datastore} = require('@google-cloud/datastore')

const datastore = new Datastore({ projectId: 'my-project' })

async function runTest () {
    const query = datastore.createQuery('my-kind')
        .filter('active', '=', true)
        .filter('account', '=', 111)
        .filter('roles', '=', 'w')
        .filter('labels', '=', 222)
        .offset(13)
    const [entities, info] = await query.run()
    console.log(`Returned ${entities.length} entities`)
}

runTest()

This code prints the following.

Returned 1 entities

Note there are currently 14 total entities (i.e., without offset). The Python script above currently returns 11 entities with offset of 13.

jacobg commented

So comparing the python implementation to node.js implementation, there is a noticeable difference on the use of the start cursor for skipping offset results.

In node.js, it uses the response's endCursor to set the next startCursor:

        query.start(info.endCursor!).offset(offset - resp.batch.skippedResults);

https://github.com/googleapis/nodejs-datastore/blob/574427a89f8ea126ce76c1732770e247e83f1514/src/request.ts#L1063

But in python, it instead uses the skipped_cursor:

            query_pb.start_cursor = response_pb.batch.skipped_cursor

python-datastore/google/cloud/datastore/query.py

Line 828 in 7fd218b

query_pb.start_cursor = response_pb.batch.skipped_cursor

In the proto file:
https://github.com/googleapis/nodejs-datastore/blob/main/protos/google/datastore/v1/query.proto
those properties are defined as follows:

  // A cursor that points to the position after the last skipped result.
  // Will be set when `skipped_results` != 0.
  bytes skipped_cursor = 3;

  // A cursor that points to the position after the last result in the batch.
  bytes end_cursor = 4;

It seems logically we should use end_cursor since the client is figuring out on its own how much to skip.

And indeed, when monkey patching the python datastore client code to use end_cursor instead of skipped_cursor, it produces the correct result! Does this seem like the exact bug and fix?

jacobg commented

That code was added trying to fix another offset bug over 4 years ago. Perhaps it wasn't a fully correct fix?
#18

daniel-sanche commented

Thanks for your detailed findings this is very helpful! My initial impression is that this does seem like the likely root cause. We'll take a look at this, add some more tests, and make sure this is addressed in the next release.

  • 👍1
  • 😄1
  • 🎉1
  • ❤️1
  • 🚀1
daniel-sanche commented

Just to make sure we're prioritizing things right: are you currently blocked on this? It may take a week or two to get the final release out, but if that timeline doesn't work for you, I can share a temporary hotfix branch or other workaround in the meantime

jacobg commented

Hi @daniel-sanche, Thanks for checking in. If you think the fix is what I proposed, I think I'll be ok, and can just pip install forked source code.

daniel-sanche commented

Hi @daniel-sanche, Thanks for checking in. If you think the fix is what I proposed, I think I'll be ok, and can just pip install forked source code.

Ok perfect. That seems to be the fix, but @gkevinzheng is going to confirm this week. We'll let you know here if we have any updates

  • 👍1
gkevinzheng commented

@jacobg Could you temporarily revert the monkey patched code to skipped_cursor to reproduce the issue, but add additional debug info for response_pb.batch.end_cursor and response_pb.batch.more_results? I'd like to get some more insight into where the discrepancy between expected and actual results is happening with the logic.

As you mentioned before, the while loop was added to fix a previous bug, and I wanted to make sure that switching to end_cursor won't reintroduce that same bug.

jacobg commented

Hi @gkevinzheng , Sure, see console output below. The cursors' project and kind are redacted. Note that current true entity count for the query is 13, and offset starts producing incorrect results at 11. Thanks.

Begin query at 2024-07-17 18:12:46.026766+00:00
Fetched all 13 entities in 1.721343994140625 seconds
Begin query at 2024-07-17 18:12:47.748346+00:00
 *** 
Fetched at offset=0 13 entities in 1.809345006942749 seconds
Begin query at 2024-07-17 18:12:49.557888+00:00
 *** 
Fetched at offset=1 12 entities in 1.5934898853302002 seconds
Begin query at 2024-07-17 18:12:51.151561+00:00
 *** 
Fetched at offset=2 11 entities in 1.6695032119750977 seconds
Begin query at 2024-07-17 18:12:52.821250+00:00
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xd2\xc2\x99\xfe\xbd\xc4\xb9\x04\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xa3\xcf\xf2\xee\xe7\xcf\x83\x02\x0c\x18\x00 \x00', more_results=1,
 *** 
Fetched at offset=3 10 entities in 1.6550030708312988 seconds
Begin query at 2024-07-17 18:12:54.476436+00:00
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xd2\xc2\x99\xfe\xbd\xc4\xb9\x04\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xa3\xcf\xf2\xee\xe7\xcf\x83\x02\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xb6\xee\xc8\x80\x97\xce\x87\x06\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x9b\xf5\x98\xcb\xb7\xfc\xd4\x05\x0c\x18\x00 \x00', more_results=1,
 *** 
Fetched at offset=4 9 entities in 1.7348220348358154 seconds
Begin query at 2024-07-17 18:12:56.211452+00:00
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xd2\xc2\x99\xfe\xbd\xc4\xb9\x04\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xa3\xcf\xf2\xee\xe7\xcf\x83\x02\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xb6\xee\xc8\x80\x97\xce\x87\x06\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x9b\xf5\x98\xcb\xb7\xfc\xd4\x05\x0c\x18\x00 \x00', more_results=1,
 *** 
Fetched at offset=5 8 entities in 1.6745400428771973 seconds
Begin query at 2024-07-17 18:12:57.886201+00:00
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xd2\xc2\x99\xfe\xbd\xc4\xb9\x04\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xa3\xcf\xf2\xee\xe7\xcf\x83\x02\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xb6\xee\xc8\x80\x97\xce\x87\x06\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x9b\xf5\x98\xcb\xb7\xfc\xd4\x05\x0c\x18\x00 \x00', more_results=1,
 *** 
Fetched at offset=6 7 entities in 1.5713188648223877 seconds
Begin query at 2024-07-17 18:12:59.457708+00:00
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xd2\xc2\x99\xfe\xbd\xc4\xb9\x04\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xa3\xcf\xf2\xee\xe7\xcf\x83\x02\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xb6\xee\xc8\x80\x97\xce\x87\x06\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x9b\xf5\x98\xcb\xb7\xfc\xd4\x05\x0c\x18\x00 \x00', more_results=1,
 *** 
Fetched at offset=7 6 entities in 1.6831982135772705 seconds
Begin query at 2024-07-17 18:13:01.141088+00:00
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xd2\xc2\x99\xfe\xbd\xc4\xb9\x04\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xa3\xcf\xf2\xee\xe7\xcf\x83\x02\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xb6\xee\xc8\x80\x97\xce\x87\x06\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x9b\xf5\x98\xcb\xb7\xfc\xd4\x05\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xfe\x84\xa6\x84\x08\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xab\x89\xb8\xe2\x80\x87\xdb\x07\x0c\x18\x00 \x00', more_results=1,
 *** 
Fetched at offset=8 5 entities in 1.4326372146606445 seconds
Begin query at 2024-07-17 18:13:02.573919+00:00
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xd2\xc2\x99\xfe\xbd\xc4\xb9\x04\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xa3\xcf\xf2\xee\xe7\xcf\x83\x02\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xb6\xee\xc8\x80\x97\xce\x87\x06\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x9b\xf5\x98\xcb\xb7\xfc\xd4\x05\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xfe\x84\xa6\x84\x08\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xab\x89\xb8\xe2\x80\x87\xdb\x07\x0c\x18\x00 \x00', more_results=1,
 *** 
Fetched at offset=9 4 entities in 1.6482799053192139 seconds
Begin query at 2024-07-17 18:13:04.222381+00:00
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xd2\xc2\x99\xfe\xbd\xc4\xb9\x04\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xa3\xcf\xf2\xee\xe7\xcf\x83\x02\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xb6\xee\xc8\x80\x97\xce\x87\x06\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x9b\xf5\x98\xcb\xb7\xfc\xd4\x05\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xfe\x84\xa6\x84\x08\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xab\x89\xb8\xe2\x80\x87\xdb\x07\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x8e\xb7\xe2\xa5\xc4\xe3\xb6\x08\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xda\xc7\xf2\xf9\xab\xbe\xab\x08\x0c\x18\x00 \x00', more_results=1,
 *** 
Fetched at offset=10 3 entities in 1.3777847290039062 seconds
Begin query at 2024-07-17 18:13:05.600341+00:00
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xd2\xc2\x99\xfe\xbd\xc4\xb9\x04\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xa3\xcf\xf2\xee\xe7\xcf\x83\x02\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xb6\xee\xc8\x80\x97\xce\x87\x06\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x9b\xf5\x98\xcb\xb7\xfc\xd4\x05\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xfe\x84\xa6\x84\x08\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xab\x89\xb8\xe2\x80\x87\xdb\x07\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x8e\xb7\xe2\xa5\xc4\xe3\xb6\x08\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xda\xc7\xf2\xf9\xab\xbe\xab\x08\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\x88\xd6\xaf\x9a\xe7\x08\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xde\xf1\xc5\xdc\x08\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\x88\xcc\x99\xc9\xe9\t\x0c\x18\x01 \x01', skipped_cursor=b'', more_results=1,
 *** 
Fetched at offset=11 12 entities in 2.114780902862549 seconds
Begin query at 2024-07-17 18:13:07.715282+00:00
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xd2\xc2\x99\xfe\xbd\xc4\xb9\x04\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xa3\xcf\xf2\xee\xe7\xcf\x83\x02\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xb6\xee\xc8\x80\x97\xce\x87\x06\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x9b\xf5\x98\xcb\xb7\xfc\xd4\x05\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xfe\x84\xa6\x84\x08\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xab\x89\xb8\xe2\x80\x87\xdb\x07\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x8e\xb7\xe2\xa5\xc4\xe3\xb6\x08\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xda\xc7\xf2\xf9\xab\xbe\xab\x08\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\x88\xd6\xaf\x9a\xe7\x08\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xde\xf1\xc5\xdc\x08\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\x88\xcc\x99\xc9\xe9\t\x0c\x18\x01 \x01', skipped_cursor=b'', more_results=1,
 *** 
Fetched at offset=12 11 entities in 2.0041160583496094 seconds
Begin query at 2024-07-17 18:13:09.719523+00:00
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xd2\xc2\x99\xfe\xbd\xc4\xb9\x04\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xa3\xcf\xf2\xee\xe7\xcf\x83\x02\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xb6\xee\xc8\x80\x97\xce\x87\x06\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x9b\xf5\x98\xcb\xb7\xfc\xd4\x05\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xfe\x84\xa6\x84\x08\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xab\x89\xb8\xe2\x80\x87\xdb\x07\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x8e\xb7\xe2\xa5\xc4\xe3\xb6\x08\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xda\xc7\xf2\xf9\xab\xbe\xab\x08\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\x88\xd6\xaf\x9a\xe7\x08\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xde\xf1\xc5\xdc\x08\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\x88\xcc\x99\xc9\xe9\t\x0c\x18\x01 \x01', skipped_cursor=b'', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xd2\xc2\x99\xfe\xbd\xc4\xb9\x04\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xa3\xcf\xf2\xee\xe7\xcf\x83\x02\x0c\x18\x00 \x00', more_results=1,
 *** 
Fetched at offset=13 10 entities in 2.0830471515655518 seconds
Begin query at 2024-07-17 18:13:11.802742+00:00
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xd2\xc2\x99\xfe\xbd\xc4\xb9\x04\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xa3\xcf\xf2\xee\xe7\xcf\x83\x02\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xb6\xee\xc8\x80\x97\xce\x87\x06\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x9b\xf5\x98\xcb\xb7\xfc\xd4\x05\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xfe\x84\xa6\x84\x08\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xab\x89\xb8\xe2\x80\x87\xdb\x07\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x8e\xb7\xe2\xa5\xc4\xe3\xb6\x08\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xda\xc7\xf2\xf9\xab\xbe\xab\x08\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\x88\xd6\xaf\x9a\xe7\x08\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\xf0\xde\xf1\xc5\xdc\x08\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x80\x80\x88\xcc\x99\xc9\xe9\t\x0c\x18\x01 \x01', skipped_cursor=b'', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xd2\xc2\x99\xfe\xbd\xc4\xb9\x04\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xa3\xcf\xf2\xee\xe7\xcf\x83\x02\x0c\x18\x00 \x00', more_results=1,
_next_page while loop: response_pb.batch end_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\xb6\xee\xc8\x80\x97\xce\x87\x06\x0c\x18\x01 \x01', skipped_cursor=b'\n7\x121j\x0cs~my-projectr!\x0b\x12\x14my_kind\x18\x9b\xf5\x98\xcb\xb7\xfc\xd4\x05\x0c\x18\x00 \x00', more_results=1,
 *** 
Fetched at offset=14 9 entities in 2.128919839859009 seconds
jacobg commented

Hi @gkevinzheng , Do you have an ETA when the pull request will be merged? Thanks.