After some more detailed logging I have isolated the problem and it is
worrying.
It so happens that I make several memcache requests, I had assumed
that since I was making
calls to the Datastore API, any delay would be due to that, but it
turns out that around
half the delay is due to the memcache calls.
Specifically, I am seeing ~13ms latency for each memcache (single get/
put/increment), and since I am
making typically 5 calls, I am seeing ~65ms delay due to this.
This is in contradiction with AppEngine System status that indicates
memcache latency ~4-5ms.
Of course, what is meant by latency vs call elapsed is a little
ambiguous, but the figures for Datastore latency
tie up with what I see in my request logs.
In other words I time the api call/return and I see around the same
figures for Datastore latency but almost three times the memcache
latency.
Is this a problem specific to the Java API perhaps?
If I batch three memcache puts using putAll, I see 13ms for the three
rather than 39ms.