I have the following piece of code in a method, which is decorated as transactional:
@ndb.transactional(retries=2, xg=True)
def add_insights(self, insights, countdown = True, forced_finish = False):
...
thing = tkey.get() ###############
logging.debug(thing.open_enrichments)
thing.insights += insight_keys
if countdown and not forced_finish:
thing.open_enrichments -= 1
if thing.open_enrichments < 0:
thing.open_enrichments = 0
elif forced_finish:
thing.open_enrichments = 0
logging.debug(thing.open_enrichments)
thing.put() #########################
This method is run in many concurrent tasks, which might access the same "thing" entity in the NDB. When I check the log files (debug statements simplified for clarity here) it seems that even if this code fails in one task, another task might still start with the decremented counter "open_enrichments" from the failed task.
I verified this with sorting the debug statements by time stamp.
The counter reaches 0 much too quickly because of this issue, of course. open_enrichments is initially set to 8 but gets (effective for other tasks reading the counter with a key.get()) decremented 12 or 13 times, which I don't understand from what I learned about transactions in NDB.
EDIT:
To clarify the sequence:
- Task A enters this piece of code with open_enrichments = 5
- Task A leaves this piece of code with open_enrichments = 4 and fails, because in the meantime
- Task B entered this piece of code with open_enrichments = 4 (not 5) !!!! it seems the >>thing = tkey.get()<< resulted in a changed entity already
- Task B leaves this piece of code with open_enrichments = 3 and commits successfully
- Task A re-enters this piece of code with open_enrichments = 3
- Task A leaves this piece of code with open_enrichments = 2 and commits
So the two tasks have run successfully only twice but the counter is decremented by 3 !!