Open10

[不完全解決]DjangoでSeparateDatabaseAndStateを使ったらpytestが落ちるようになった問題

Hideki IkemotoHideki Ikemoto

Djangoでモデルを別のアプリケーションに移動するためにSeparateDatabaseAndStateを使ったのですが、それによってpytestが落ちるようになってしまいました。この問題を解決したいと思います。

Hideki IkemotoHideki Ikemoto

こちらの問題、いつの間にか発生しなくなってました。何が原因かは結局分かりませんでした。

Hideki IkemotoHideki Ikemoto

まず状況から。

プライベートサイトをDjango + Herokuで作っています。
DBはPostgreSQLですが、CI(CirleCI)はSQLiteを使っています。

問題は、CIは通ること。CIは通る、でもローカルMacでpytestコマンドを流すと落ちる。
SeparateDatabaseAndStateを使う前のコミットでは通るので、SeparateDatabaseAndStateを使ったコミットがマズいのは確か。

エラーはこんな感じ。

E django.core.management.base.CommandError: Database file:memorydb_default?mode=memory&cache=shared couldn't be flushed. Possible reasons:
E * The database isn't running or isn't configured correctly.
E * At least one of the expected database tables doesn't exist.
E * The SQL was invalid.
E Hint: Look at the output of 'django-admin sqlflush'. That's the SQL this command wasn't able to run.

こんなエラーも出ている。 life_basetask というテーブルがないと言われています。
しかしこれは変です。life アプリの BaseTask というモデルを task アプリに移動してそれからリネームしたので、 task_basetask という名前でないといけない。実際、それで動いています(今使ってないモデルなので、Django管理画面で確認)。

E sqlite3.OperationalError: no such table: main.life_basetask

あとこんなエラーも出てます。よく分からない。

E django.db.utils.IntegrityError: UNIQUE constraint failed: social_auth_usersocialauth.provider, social_auth_usersocialauth.uid

Hideki IkemotoHideki Ikemoto

とりあえず雑に django.core.management.base.CommandError: Database file:memorydb_default?mode=memory&cache=shared couldn't be flushed. でググる。

Django "flush" management command fails because of "wagtailsearch_editorspick" table · Issue #1824 · wagtail/wagtail
別アプリだけど状況は似ている。未解決。

python - database_table locked during automated tests with Selenium Django - Stack Overflow
ロックされている?関係なさそうに見える。

python - Django can't flush database during tests - Stack Overflow
同じような現象っぽい。Django 3.1.2でも出るというコメントあり。

Djangoの公式サイトでも検索(キーワード: couldn't be flushed)。未解決のものは見つからず。

Hideki IkemotoHideki Ikemoto

CIだけ通るという状況的に、環境周りが怪しそうなのでまずはCI環境との差異を調べる。

まず目に入ったのはPython。ローカルMacが3.7.7、CI環境が3.7.8。
ローカルの方が古い。

とりあえずローカルを3.7.9に上げる。

brew unlink python
brew link python@3.7

venvも再構築。パッケージも入れ直し。
結果は、ダメでした。

とりあえずCI環境も3.7.9に上げておきました。
本番環境は既に3.7.9でした。

Hideki IkemotoHideki Ikemoto

pytest --nomigrationsの件。

pytestには--nomigrationsというオプションがあって、これを使うとマイグレーションファイルではなく、実際のモデルからテストに使うDBを設定します。

これを使ってローカルでテストを実行すると通りました。
もちろんCI環境には入れていません。
逆に言えば、マイグレーションファイルかマイグレーションシステムに問題がありそうだと分かります。

Hideki IkemotoHideki Ikemoto

次に気になったのはsqlite3。

  • CI環境: libsqlite3-0/stable,now 3.27.2-3+deb10u1 amd64 [installed,automatic]
  • macOS: 3.34.0

公式サイトを見ると3.34.1が出てますが、変更点を見る限り関係なさそうに見えるので一旦保留。

Hideki IkemotoHideki Ikemoto

環境の差異で調べても難しそうだなぁと感じたので、状況調査に戻ります。
いろいろテストしてて気づいたのですが、1個目のテストが常に通ります。2個目のテストからNG。
しかも、1個だけテストを流すとテストは成功するのですが、エラーが出ます。

こんな感じのコードを通ってることが分かります。
ここらへん

    def _post_teardown(self):
        """
        Perform post-test things:
        * Flush the contents of the database to leave a clean slate. If the
          class has an 'available_apps' attribute, don't fire post_migrate.
        * Force-close the connection so the next test gets a clean cursor.
        """
        try:
>           self._fixture_teardown()

テストは通るが、後片付けで何か問題がありそうな感じです。

しかし、ログを見てもよく分からないです。

self = <django.db.backends.utils.CursorWrapper object at 0x10e6dff50>, sql = 'DELETE FROM "task_oneshottask";', params = None
ignored_wrapper_args = (False, {'connection': <django.db.backends.sqlite3.base.DatabaseWrapper object at 0x10cc99310>, 'cursor': <django.db.backends.utils.CursorWrapper object at 0x10e6dff50>})

    def _execute(self, sql, params, *ignored_wrapper_args):
        self.db.validate_no_broken_transaction()
        with self.db.wrap_database_errors:
            if params is None:
                # params default might be backend specific.
>               return self.cursor.execute(sql)

venv/lib/python3.7/site-packages/django/db/backends/utils.py:82: 
_ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ 

self = <django.db.backends.sqlite3.base.SQLiteCursorWrapper object at 0x10e245910>, query = 'DELETE FROM "task_oneshottask";'
params = None

    def execute(self, query, params=None):
        if params is None:
>           return Database.Cursor.execute(self, query)
E           sqlite3.OperationalError: no such table: main.life_nextaction

venv/lib/python3.7/site-packages/django/db/backends/sqlite3/base.py:411: OperationalError
Hideki IkemotoHideki Ikemoto

現状までのまとめ

  • SeparateDatabaseAndState を使うとおきる
  • pytestで --nomigrations をつけると回避できる
  • macOSでは起きるが、CI環境(Ubuntu)ではおきない
  • teardownが正しく動いてない模様

現象としては再現性があるのですが、バグ報告するにしても今のアプリは規模が大きいので、もうちょっと小さいプログラムで再現させた方がいいのかなぁと思ってます。