How fast are App Engine db.get(keys) and A.all(keys_only=True).filter('b =', b).fetch(1000)?

Question

A db.get() of 50 keys seems to take me 5-6 seconds. Is that normal? What is the time a function of?

I also did a A.all(keys_only=True).filter('b =', b).fetch(1000) where A.b is a ReferenceProperty. I did 50 such round trips to the datastore, with different values of b, and the total time was only 3-4 seconds.

How is this possible? db.get() is done in parallel, with only one trip to the datastore, and I would think that looking up an entity by key is a faster operation than fetch.

Here is the definition for my class A:

class App(db.Model):
    name_atom = db.ReferenceProperty(AppName)
    author = db.ReferenceProperty(Author)
    short_desc = db.StringProperty()
    description = db.TextProperty()
    url = db.StringProperty()
    rating_avg = properties.RangeProperty(0, 1000, default=0)
    rating_count = properties.RangeProperty(min_value=0, default=0)
    add_dt = db.DateTimeProperty(auto_now_add=True)
    modify_dt = db.DateTimeProperty(auto_now=True)

Update

OK, AppStats says: datastore_v3.Get real=2272ms api=416ms

I think what's happening is that I'm doing this db.get([50 keys]) right after a ton of other inefficient datastore calls in the same request handler, and it's just rate limiting me or something. Other times I've done the same db.get() and it returned in 200ms :)

Answer 1

When fetching entities by key, query time should primarily be dependent on the size of your entities. The entities have to be transferred to you over the network and then decoded.

Perhaps your entities are quite large? This might explain why your keys_only query is faster despite the fact it includes a filter and fetches many more results.

You might consider using AppStats so you can see exactly why your request is taking so long. You could even post it along with your question.

Answer 2

A db.get() of 50 keys seems to take me 5-6 seconds. Is that normal? What is the time a function of?

No. It should take a couple of hundred milliseconds. How are you timing it, though?

I also did a A.all(keys_only=True).filter('b =', b).fetch(1000) where A.b is a ReferenceProperty. I did 50 such round trips to the datastore, with different values of b, and the total time was only 3-4 seconds.

That's not unreasonable, for 50 roundtrips.

How is this possible? db.get() is done in parallel, with only one trip to the datastore, and I would think that looking up an entity by key is a faster operation than fetch.

It's an extremely odd result, and I think that there are likely confounding factors at work. As David suggests, you should use AppStats to discover where the time is going.