Djangoのキャッシュ機能を使って画面表示を高速化する データベース編

2018年12月19日追記

キャッシュ保存先をデータベースよりもメリットの多いMemcachedにする方法の記事を投稿しました。
Djangoでキャッシュを使おうと考えている方はぜひこちらをご覧ください。

[Djangoのキャッシュ機能を使って画面表示をもっと高速化する Memcached編](https://qiita.com/shonansurvivors/items/f2681aebfd8b08cee994)

#はじめに

Djangoのキャッシュ機能を使って、画面表示の高速化にトライしてみました。

#1. キャッシュを使う方法

今回、キャッシュを保存する先はデータベースとしました。

その他の保存先としてファイルや、memcachedという仕組みを使うこともできるようです。

##1.1. settings.pyにキャッシュの設定を行う

`settings.py`に以下を追加します。

```python:settings.py
CACHES = {
    'default': {
        'BACKEND': 'django.core.cache.backends.db.DatabaseCache',
        'LOCATION': 'my_cache_table',
    }
}
```

`BACKEND`の部分がキャッシュの保存先の種類を示していて、`db.DatabaseCashe`とあるとおり、データベースとなっています。

`LOCATION`の部分は、キャッシュを保存するテーブルの名前になります。好きな名前をつけて構いませんが、既に存在するテーブルの名前と被らないようにする必要があります。今回は`my_cache_table`としています。

##1.2. キャッシュ用のテーブルを作成する

ターミナルで以下を実行することで、さきほどの`my_cache_table`が作られます。

```shell
$ python manage.py createcachetable
```

テーブルの作成、と聞くと`models.py`でmodelの定義を追加・変更した時のようにマイグレーションも行う必要があるのでは、と思ってしまいましたが、キャッシュ用のテーブル作成に関してはその必要はありません。

`makemigrations`を行っても、

```shell
$ python manage.py makemigrations
No changes detected
```

何の変化も無いよ、と表示されます。

##1.3. キャッシュ用のテーブルの定義を見てみる

`python manage.py createcachetable`によって、どのようなテーブルが作られたのでしょうか？気になるので見てみることにします。

Djangoの管理画面で見ることができれば手軽で良いのですが、やり方がわからなかったのでデータベースのコマンドを使うことにします。

###Djangoの`dbshell`を起動する

```shell
$ python manage.py dbshell
```

`dbshell`を起動すると以下のような表示になります（データベースにSQLiteを使っている場合）。

```shell
SQLite version 3.19.3 2017-06-27 16:48:08
Enter ".help" for usage hints.
sqlite> 
```
###キャッシュ用のテーブル作成に使われたSQLを見る

次に`.schema`に続けて、キャッシュ用のテーブル名を指定することで、テーブルの定義を見ることができます（`.schema`が使えるのはデータベースがSQLiteの場合です。他のデータベースの場合は違うコマンドになります）。

```shell
sqlite>.schema my_cache_table 
```

すると、キャッシュ用のテーブルを作成する時に使われたSQLが表示されます。ここから、キャッシュ用テーブルがどのようなカラムを持っているのかがわかります。

```sql
CREATE TABLE IF NOT EXISTS "my_cache_table" (
    "cache_key" varchar(255) NOT NULL PRIMARY KEY,
    "value" text NOT NULL,
    "expires" datetime NOT NULL
);
CREATE INDEX "my_cache_table_expires" ON "my_cache_table" ("expires");
```

- キーである`cache_key`
- キャッシュ情報である`value`
- キャッシュの有効期限である`expires`

の3カラムだけのシンプルなテーブルでした。

##1.4. キャッシュする対象を指定する

今回はアクセスの多い特定のURLのページだけをキャッシュすることにしました。そのような場合は、`urls.py`でキャッシュする対象を指定します。

もともとの`urls.py`が以下のような内容だった場合・・・

```python:urls.py（修正前）
from django.urls import path
from . import views

urlpatterns = [
    path('', views.ArticleListView.as_view(), name='article_list'),
    # 略
]
```

以下のように`cache_page`関数を使います。秒数の部分は`60 * 15`と記述することで15分であることをわかりやすくしています。

```python:urls.py（修正後）
from django.urls import path
from django.views.decorators.cache import cache_page # ここを追加
from . import views


urlpatterns = [
    # cache_page(秒数)(ビュー)を追加する
    path('', cache_page(60 * 15)(views.ArticleListView.as_view()), name='article_list'),
    # 略
]
```

#2. キャッシュによりDjangoの動きがどのように変わったかを見てみる

キャッシュ設定前後で何が変わったのかをdjango-debug-toolbarの機能を使って見てみることにします。

django-debug-toolbarの設定方法は以下を参考にさせていただきました。

[Djangoメモ(14) : Django Debug Toolbarでデバッグ情報を表示](https://wonderwall.hatenablog.com/entry/2018/03/13/233000)

##2.1. キャッシュ設定無し

<img width="778" alt="スクリーンショット 2018-11-24 0.11.08.png" src="https://qiita-image-store.s3.amazonaws.com/0/317369/a66fc7ce-8620-9823-50cb-0afdae98ec8b.png">

画面は自作のDjangoアプリです。
右端の黒いツールバー部分がdjango-debug-toolbarによって表示されている情報です。
「時刻」に表示されているのがCPUの処理時間だと思われます。約181ミリ秒かかっています。
なお、SQLは5本発行されてます。

ちなみに処理時間の内訳は以下のようになっています。

<img width="780" alt="スクリーンショット 2018-11-24 0.16.16.png" src="https://qiita-image-store.s3.amazonaws.com/0/317369/141c099d-26cc-e42c-3b8e-3c55f2223417.png">


##2.2. キャッシュ設定ありの時の初回のアクセス

<img width="780" alt="スクリーンショット 2018-11-23 23.54.14.png" src="https://qiita-image-store.s3.amazonaws.com/0/317369/03558380-44cc-4a97-170e-12c3fc09f6bb.png">

処理時間が約335ミリ秒(+154ミリ秒)に増えてしまいました。
また、SQLの発行本数も14本(+9本)に増えています。

SQLの本数が増えたのはキャッシュ用のテーブルへの読み書きを行ったためのようです。
キャッシュの有無を調べるSQL、(キャッシュが無いので)ページの情報をキャッシュへ書き込むSQLが発行されていました。

SQLの本数が増えたことでSQLの処理時間が31ミリ秒から41ミリ秒と、10ミリ秒増加していることは理解できるのですが、これに対してCPUの処理時間がプラス154ミリ秒と大幅に増えている理由が私にはわかっていません・・・。SQLの処理時間とは別に、何の処理に時間がかかってしまっているんでしょうか？データベースへのアクセス待ちの時間？

処理時間の内訳は以下のとおりです。
<img width="774" alt="スクリーンショット 2018-11-23 23.59.18.png" src="https://qiita-image-store.s3.amazonaws.com/0/317369/ad3fd188-2950-c862-cbe8-623b73452a20.png">

##2.3. キャッシュ設定ありの時の2回目のアクセス

<img width="769" alt="スクリーンショット 2018-11-24 0.02.36.png" src="https://qiita-image-store.s3.amazonaws.com/0/317369/efa1854e-2ef3-a48b-74fe-f5479471ded5.png">

処理時間が約23ミリ秒と大幅に減りました(-158ミリ秒)。
また、SQLの発行本数も2本(-3本)と少なくなりました。SQLはキャッシュ用テーブルをSELECTするだけになっていて、他のテーブルへのアクセスが無くなっています。

処理時間の内訳は以下のとおりです。
<img width="770" alt="スクリーンショット 2018-11-24 0.04.11.png" src="https://qiita-image-store.s3.amazonaws.com/0/317369/2797fea2-b04f-15fd-4b99-450d5ecbeebf.png">

# まとめ

|条件                         |CPU処理時間(ms)|SQL本数|
|:---------------------------|-------------:|:----:|
| キャッシュ設定無し              |181           |5|
| キャッシュ設定あり・初回アクセス    |335           |14|
| キャッシュ設定あり・2回目のアクセス | 23           |2|


たったの1回ずつしかアクセスしていないので厳密な検証ではありませんが、データベースをキャッシュに使った場合、初回のアクセスはキャッシュ設定無しの時よりも画面表示に時間がかかってしまいますが、2回目以降のアクセスは大幅に時間が短くなることが期待できるようです。



#参考

[Django’s cache framework](https://docs.djangoproject.com/en/2.1/topics/cache/)