[Dd]enzow(ill)? with DB and Python

DBとか資格とかPythonとかの話をつらつらと

DjangoのATOMIC_REQUESTSの挙動について

今回はDjangoのsettings.DATABASESに指定できるATOMIC_REQUESTSという設定について挙動を確認してみます。なおデータベースにはPostgreSQLを利用します。

アプリ構成

関連するファイルはこんな感じになっています。

settings.py(データベース周りだけ)

とくに変わったことはせず、PostgreSQLをDjangoで使う場合の標準的な設定にしています。

DATABASES = {
    'default': {
        'ENGINE': 'django.db.backends.postgresql_psycopg2',
        'NAME': 'djangodb',
        'USER': 'hoge',
        'PASSWORD': 'password',
        'HOST': 'localhost',
        'PORT': '5432',
    }
}

models.py

商品マスター(Product)と注文管理(ProductOrder)を定義しておきます。

class Product(models.Model):

    name = models.CharField(verbose_name='商品名', max_length=100)
    price = models.IntegerField(verbose_name='価格')

    def __str__(self):
        return '{} {}'.format(self.id, self.name)


class ProductOrder(models.Model):

    product = models.ForeignKey('Product', verbose_name='注文商品', related_name='orderd_product')
    amount = models.IntegerField(verbose_name='注文数')
    order_date = models.DateField(verbose_name='注文日', auto_now=True)

    def __str__(self):
        return '{} {} {}'.format(self.product, self.amount, self.order_date)

views.py

とりあえず、商品IDが1,2のものを購入する2つのProductOrderを生成して保存する処理を用意し、この場合のsaveの動きを見ていきます。なお、urls.py/buyへのアクセスでbuy()が実行されるようにしておきます。また、SQLが発行されたタイミングがどのコードであるかを追いやすくするため適宜sleepをいれておきます。

def buy(request):

    product_1 = Product.objects.get(pk=1)
    product_2 = Product.objects.get(pk=2)
    time.sleep(2)
    one_order = ProductOrder(
        product=product_1,
        amount=10
    )
    time.sleep(3)
    one_order.save()
    time.sleep(4)
    two_order = ProductOrder(
        product=product_2,
        amount=10
    )
    time.sleep(5)
    two_order.save()
    time.sleep(6)
    return HttpResponse('ordered')

postgresql.conf

すべてのSQLがログ出力されるように以下を設定し、再起動しておきます。

log_min_duration_statement = 0

初期状態での動作確認

単純に/buyへアクセスした場合、以下のようなSQLが発行されました。

[2018-01-21 12:55:07 UTC][81][hoge][djangodb] LOG:  duration: 0.553 ms  statement: SELECT "myapp_product"."id", "myapp_product"."name", "myapp_product"."price" FROM "myapp_product" WHERE "myapp_product"."id" = 1
[2018-01-21 12:55:07 UTC][81][hoge][djangodb] LOG:  duration: 0.158 ms  statement: SELECT "myapp_product"."id", "myapp_product"."name", "myapp_product"."price" FROM "myapp_product" WHERE "myapp_product"."id" = 2
[2018-01-21 12:55:12 UTC][81][hoge][djangodb] LOG:  duration: 0.041 ms  statement: BEGIN
[2018-01-21 12:55:12 UTC][81][hoge][djangodb] LOG:  duration: 0.636 ms  statement: INSERT INTO "myapp_productorder" ("product_id", "amount", "order_date") VALUES (1, 10, '2018-01-21'::date) RETURNING "myapp_productorder"."id"
[2018-01-21 12:55:12 UTC][81][hoge][djangodb] LOG:  duration: 1.067 ms  statement: COMMIT
[2018-01-21 12:55:21 UTC][81][hoge][djangodb] LOG:  duration: 0.043 ms  statement: BEGIN
[2018-01-21 12:55:21 UTC][81][hoge][djangodb] LOG:  duration: 0.260 ms  statement: INSERT INTO "myapp_productorder" ("product_id", "amount", "order_date") VALUES (2, 10, '2018-01-21'::date) RETURNING "myapp_productorder"."id"
[2018-01-21 12:55:21 UTC][81][hoge][djangodb] LOG:  duration: 1.813 ms  statement: COMMIT

発行されたSQLとコードを突き合わせるとこんな感じですね。

def buy(request):
    # [2018-01-21 12:55:07 UTC][81][hoge][djangodb] LOG:  duration: 0.553 ms  statement: SELECT "myapp_product"."id", "myapp_product"."name", "myapp_product"."price" FROM "myapp_product" WHERE "myapp_product"."id" = 1
    product_1 = Product.objects.get(pk=1)
    # [2018-01-21 12:55:07 UTC][81][hoge][djangodb] LOG:  duration: 0.158 ms  statement: SELECT "myapp_product"."id", "myapp_product"."name", "myapp_product"."price" FROM "myapp_product" WHERE "myapp_product"."id" = 2
    product_2 = Product.objects.get(pk=2)
    time.sleep(2)
    one_order = ProductOrder(
        product=product_1,
        amount=10
    )
    time.sleep(3)
    # 2 + 3 の5秒後に実行されている
    # [2018-01-21 12:55:12 UTC][81][hoge][djangodb] LOG:  duration: 0.041 ms  statement: BEGIN
    # [2018-01-21 12:55:12 UTC][81][hoge][djangodb] LOG:  duration: 0.636 ms  statement: INSERT INTO "myapp_productorder" ("product_id", "amount", "order_date") VALUES (1, 10, '2018-01-21'::date) RETURNING "myapp_productorder"."id"
    # [2018-01-21 12:55:12 UTC][81][hoge][djangodb] LOG:  duration: 1.067 ms  statement: COMMIT
    one_order.save()
    time.sleep(4)
    two_order = ProductOrder(
        product=product_2,
        amount=10
    )
    time.sleep(5)
    # 4 + 5 の9秒後に実行されている
    # [2018-01-21 12:55:21 UTC][81][hoge][djangodb] LOG:  duration: 0.043 ms  statement: BEGIN
    # [2018-01-21 12:55:21 UTC][81][hoge][djangodb] LOG:  duration: 0.260 ms  statement: INSERT INTO "myapp_productorder" ("product_id", "amount", "order_date") VALUES (2, 10, '2018-01-21'::date) RETURNING "myapp_productorder"."id"
    # [2018-01-21 12:55:21 UTC][81][hoge][djangodb] LOG:  duration: 1.813 ms  statement: COMMIT
    two_order.save()
    time.sleep(6)
    return HttpResponse('ordered')

save()を実行するごとにCOMMITが発行されていることがわかります。では以下のようにATOMIC_REQUESTTrueに設定してみます。

DATABASES = {
    'default': {
        'ENGINE': 'django.db.backends.postgresql_psycopg2',
        'NAME': 'djangodb',
        'USER': 'hoge',
        'PASSWORD': 'password',
        'HOST': 'localhost',
        'PORT': '5432',
        'ATOMIC_REQUESTS': True,  # ここを変更
    }
}

この状態で同じように/buyに実行してみます。

[2018-01-21 12:58:42 UTC][91][hoge][djangodb] LOG:  duration: 0.064 ms  statement: BEGIN
[2018-01-21 12:58:42 UTC][91][hoge][djangodb] LOG:  duration: 0.600 ms  statement: SELECT "myapp_product"."id", "myapp_product"."name", "myapp_product"."price" FROM "myapp_product" WHERE "myapp_product"."id" = 1
[2018-01-21 12:58:42 UTC][91][hoge][djangodb] LOG:  duration: 0.119 ms  statement: SELECT "myapp_product"."id", "myapp_product"."name", "myapp_product"."price" FROM "myapp_product" WHERE "myapp_product"."id" = 2
[2018-01-21 12:58:48 UTC][91][hoge][djangodb] LOG:  duration: 0.517 ms  statement: INSERT INTO "myapp_productorder" ("product_id", "amount", "order_date") VALUES (1, 10, '2018-01-21'::date) RETURNING "myapp_productorder"."id"
[2018-01-21 12:58:57 UTC][91][hoge][djangodb] LOG:  duration: 0.294 ms  statement: INSERT INTO "myapp_productorder" ("product_id", "amount", "order_date") VALUES (2, 10, '2018-01-21'::date) RETURNING "myapp_productorder"."id"
[2018-01-21 12:59:03 UTC][91][hoge][djangodb] LOG:  duration: 2.139 ms  statement: COMMIT

BEGIN, COMMITの発行が1回だけになっています。コードとの突き合わせをしてみます。

def buy(request):
    # [2018-01-21 12:58:42 UTC][91][hoge][djangodb] LOG:  duration: 0.064 ms  statement: BEGIN
    # [2018-01-21 12:58:42 UTC][91][hoge][djangodb] LOG:  duration: 0.600 ms  statement: SELECT "myapp_product"."id", "myapp_product"."name", "myapp_product"."price" FROM "myapp_product" WHERE "myapp_product"."id" = 1    
    product_1 = Product.objects.get(pk=1)
    # [2018-01-21 12:58:42 UTC][91][hoge][djangodb] LOG:  duration: 0.119 ms  statement: SELECT "myapp_product"."id", "myapp_product"."name", "myapp_product"."price" FROM "myapp_product" WHERE "myapp_product"."id" = 2
    product_2 = Product.objects.get(pk=2)
    time.sleep(2)
    one_order = ProductOrder(
        product=product_1,
        amount=10
    )
    time.sleep(3)
    # [2018-01-21 12:58:48 UTC][91][hoge][djangodb] LOG:  duration: 0.517 ms  statement: INSERT INTO "myapp_productorder" ("product_id", "amount", "order_date") VALUES (1, 10, '2018-01-21'::date) RETURNING "myapp_productorder"."id"
    one_order.save()
    time.sleep(4)
    two_order = ProductOrder(
        product=product_2,
        amount=10
    )
    time.sleep(5)
    # [2018-01-21 12:58:57 UTC][91][hoge][djangodb] LOG:  duration: 0.294 ms  statement: INSERT INTO "myapp_productorder" ("product_id", "amount", "order_date") VALUES (2, 10, '2018-01-21'::date) RETURNING "myapp_productorder"."id"
    two_order.save()
    time.sleep(6)
    # [2018-01-21 12:59:03 UTC][91][hoge][djangodb] LOG:  duration: 2.139 ms  statement: COMMIT
    return HttpResponse('ordered')

viewのメソッド全体が1トランザクションになるようにBEGIN-COMMITで挟まれており、正常にレスポンスを戻した場合にCOMMITさるようになります。また個別のsaveではトランザクションを確定させないように変わっています。そのため、view内でDBへ複数の処理をしている場合でもATOMICになるようになります。

例えば、以下のように処理中に例外が発生する場合はROLLBACKされるようになります。

def rollback_buy(request):

    product_1 = Product.objects.get(pk=1)
    product_2 = Product.objects.get(pk=2)
    one_order = ProductOrder(
        product=product_1,
        amount=10
    )
    one_order.save()
    raise Exception('rollback occur!')

    return HttpResponse('ordered')
  • 実行時のログ
[2018-01-21 13:17:43 UTC][139][hoge][djangodb] LOG:  duration: 0.061 ms  statement: BEGIN
[2018-01-21 13:17:43 UTC][139][hoge][djangodb] LOG:  duration: 1.676 ms  statement: SELECT "myapp_product"."id", "myapp_product"."name", "myapp_product"."price" FROM "myapp_product" WHERE "myapp_product"."id" = 1
[2018-01-21 13:17:43 UTC][139][hoge][djangodb] LOG:  duration: 0.175 ms  statement: SELECT "myapp_product"."id", "myapp_product"."name", "myapp_product"."price" FROM "myapp_product" WHERE "myapp_product"."id" = 2
[2018-01-21 13:17:43 UTC][139][hoge][djangodb] LOG:  duration: 0.489 ms  statement: INSERT INTO "myapp_productorder" ("product_id", "amount", "order_date") VALUES (1, 10, '2018-01-21'::date) RETURNING "myapp_productorder"."id"
[2018-01-21 13:17:43 UTC][139][hoge][djangodb] LOG:  duration: 0.179 ms  statement: ROLLBACK

COMMITではなくROLLBACKが発行されています。もちろん、以下のようにtry..exceptし、レスポンスを正しく戻す場合はCOMMITになります。

def rollback_buy(request):

    product_1 = Product.objects.get(pk=1)
    product_2 = Product.objects.get(pk=2)
    one_order = ProductOrder(
        product=product_1,
        amount=10
    )
    one_order.save()
    try:
        raise Exception('rollback occur!')
    except:
        pass

    return HttpResponse('ordered')

ATOMIC_REQUESTS がTrueのときのROLLBACK

ATOMIC_REQUESTS = TRUEの場合、上述のようにレスポンスが正常に戻らない場合にROLLBACKされます。しかし、処理によっては任意のタイミングでROLLBACKが必要なケースもあります。その場合、どのようにするべきでしょうか。

Tying transactions to HTTP requests

に少しありますが、@transaction.non_atomic_requestsを付与してそのメソッドについてはATOMIC_REQUESTS = FALSEの状態にするなどして自分でトランザクション管理をする必要が有るようです。これは結局Djangoのデフォルト状態の動作にするということですので、ATOMIC_REQUESTS = TRUEが効果的な処理が少ないのであれば、それらだけ@transaction.atomicを付与するという対応もありかもしれません。

その他詳しいことは以下のドキュメントが参考になると思います。

Database transactions