different entity group on transaction using google-cloud-ndb

Question

I would like to run a transaction operation in Google App Engine using google-cloud-ndb. I deployed this app.

Here is my code.

# -*- coding: utf-8 -*-
from flask import Flask
from google.cloud import ndb
import time

app = Flask(__name__)

class Book(ndb.Model):
    hoge = ndb.IntegerProperty()
class Book2(ndb.Model):
    hoge = ndb.IntegerProperty()

@ndb.transactional()
def test1():
    ent = ndb.Key(Book, "a").get()
    print("after get: %s", ent)
    ent.hoge = ent.hoge + 1
    ent.put()
    print("after put: %s", ent)
    print("wakeup")

@ndb.transactional()
def test2():
    ent = ndb.Key(Book2, "a").get()
    print("after get: %s", ent)
    ent.hoge = ent.hoge + 1
    ent.put()
    print("after put: %s", ent)
    time.sleep(10)
    print("wakeup")

@app.route('/piyo')
def piyo():
    print("before transaction")
    try:
        with ndb.Client().context():
            print("enter transaction")
            test1()
    except Exception as e:
        print(e)
    print("completed")
    return '', 204

@app.route('/foo')
def foo():
    print("before transaction")
    try:
        with ndb.Client().context():
            print("enter transaction")
            test2()
    except Exception as e:
        print(e)
    print("completed")
    return '', 204

if __name__ == "__main__":
    app.run()

The attempt to run this will unexpected result for me. Datastore dont conflict for different entity-groups(As far as i know). But they seem to be conflicting and wait completing the preceding operation.

Why does this work?

Logging:

2020-01-30 21:23:18.878 GET 204 116B 10.3s /foo
2020-01-30 21:23:18.882 before transaction
2020-01-30 21:23:18.887 enter transaction
2020-01-30 21:23:19.061 after get: %s Book2(key=Key('Book2', 'a'), hoge=33)
2020-01-30 21:23:19.062 after put: %s Book2(key=Key('Book2', 'a'), hoge=34)
★ sleep
2020-01-30 21:23:29.062 wakeup
2020-01-30 21:23:29.130 completed

2020-01-30 21:23:22.699 GET 204 116B 6.6s Android /piyo
★ confrict and wait completing "Book2" transaction
2020-01-30 21:23:29.132 before transaction
2020-01-30 21:23:29.136 enter transaction
2020-01-30 21:23:29.221 after get: %s Book(key=Key('Book', 'a'), hoge=30)
2020-01-30 21:23:29.221 after put: %s Book(key=Key('Book', 'a'), hoge=31)
2020-01-30 21:23:29.221 wakeup
2020-01-30 21:23:29.285 completed

I'm using Python 3.7. I have these tools installed in my environment:

Flask==1.0.3
google-cloud-ndb==0.2.2

Please help me with my problem. Thank you before

Answer 1

Technically you don't have a conflict since you're operating on different entity groups.

There is however room for potential conflicts while both cross-group transactional calls are still in progress - you don't know yet if any of them won't access an entity touched by the other one. BTW, the accesses don't have to be just entity writes (causing conflicts), they could just as well be entity reads (causing contention), see Contention problems in Google App Engine.

But as soon as a transactional call ends I'd expect its transaction to complete (one way or another, not really relevant in this case) without waiting for some other transactional call still in progress to end as well, regardless of it being started earlier or not. The behaviour observed - the fact that a transactional call being ready for completion keeps waiting for some other transactional call still in progress - can cause severe app performance degradation. Unless something was missed it would probably indicate a bug of some sort.

One thing that can be tried (as an experiment only) is to force the 2 transactions to be executed by different GAE instances, by configuring automatic_scaling with max_concurrent_requests set to 1 in the app.yaml file:

Optional. The number of concurrent requests an automatic scaling instance can accept before the scheduler spawns a new instance (Default: 10, Maximum: 80).

...

We recommend you do not set max_concurrent_requests to less than 10 unless you need single threading. A value of less than 10 is likely to result in more instances being created than you need for a threadsafe app, and that may lead to unnecessary cost.

Executing in separate instances would ensure total isolation of the client context. If the symptom goes away the problem is on the client side, possibly in the cloud ndb library - maybe some (undesired) serialization? I'd file an issue at https://github.com/googleapis/python-ndb (I scanned the issues filed in the past several months, those still open as well as recently merged PRs, I didn't notice anything apparently related).

If the symptom persists for transactions from different, isolated clients then the problem is somewhere on the datastore side. Maybe related to the transition from the older datastore to the firestore in datastore mode? - I think I would have noticed such behaviour with the old datastore, I did extensive testing for my transaction-heavy app before the transition. I'd file an issue at https://issuetracker.google.com/.