Django生产环境添加字段迁移超时求助（PostgreSQL）

我有一张持续被写入的日志表request_log_requestlog2，想要为其添加request_type字段，本地迁移执行正常，但生产环境执行时出现超时。

迁移文件 #

from django.db import migrations, models


class Migration(migrations.Migration):

    dependencies = [
        ("request_log", "0004_requestlog2"),
    ]

    operations = [
        migrations.AddField(
            model_name="requestlog2",
            name="request_type",
            field=models.PositiveSmallIntegerField(
                blank=True,
                choices=[(0, "Incoming"), (1, "Outgoing"), (2, "Internal")],
                help_text="State the type on request",
                null=True,
            ),
        ),
    ]

迁移报错日志 #

Rendering model states... DONE
  Applying request_log.0005_requestlog2_request_type...django 21/Oct/2022:15:12:54,194347 +0000 [INFO] squadrun.sentry_helpers: thread=140715699507328 extra: exchash: b8ca65d21d0d448f8fe90658c0708923 detected
Traceback (most recent call last):
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/django/db/backends/utils.py", line 64, in execute
    return self.cursor.execute(sql, params)
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/elasticapm/instrumentation/packages/dbapi2.py", line 210, in execute
    return self._trace_sql(self.__wrapped__.execute, sql, params)
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/elasticapm/instrumentation/packages/dbapi2.py", line 244, in _trace_sql
    result = method(sql, params)
psycopg2.extensions.QueryCanceledError: canceling statement due to statement timeout


The above exception was the direct cause of the following exception:

Traceback (most recent call last):
  File "manage.py", line 40, in <module>
    execute_from_command_line(sys.argv)
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/django/core/management/__init__.py", line 353, in execute_from_command_line
    utility.execute()
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/django/core/management/__init__.py", line 345, in execute
    self.fetch_command(subcommand).run_from_argv(self.argv)
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/django/core/management/base.py", line 348, in run_from_argv
    self.execute(*args, **cmd_options)
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/django/core/management/base.py", line 399, in execute
    output = self.handle(*args, **options)
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/django/core/management/commands/migrate.py", line 200, in handle
    executor.migrate(targets, plan, fake=fake, fake_initial=fake_initial)
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/django/db/migrations/executor.py", line 92, in migrate
    self._migrate_all_forwards(plan, full_plan, fake=fake, fake_initial=fake_initial)
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/django/db/migrations/executor.py", line 121, in _migrate_all_forwards
    state = self.apply_migration(state, migration, fake=fake, fake_initial=fake_initial)
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/django/db/migrations/executor.py", line 198, in apply_migration
    state = migration.apply(state, schema_editor)
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/django/db/migrations/migration.py", line 123, in apply
    operation.database_forwards(self.app_label, schema_editor, old_state, project_state)
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/django/db/migrations/operations/fields.py", line 62, in database_forwards
    field,
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/django/contrib/gis/db/backends/postgis/schema.py", line 69, in add_field
    super(PostGISSchemaEditor, self).add_field(model, field)
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/django/db/backends/base/schema.py", line 396, in add_field
    self.execute(sql, params)
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/django/db/backends/base/schema.py", line 110, in execute
    cursor.execute(sql, params)
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/sentry_sdk/integrations/django/__init__.py", line 446, in execute
    return real_execute(self, sql, params)
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/django/db/backends/utils.py", line 64, in execute
    return self.cursor.execute(sql, params)
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/django/db/utils.py", line 95, in __exit__
    six.reraise(dj_exc_type, dj_exc_value, traceback)
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/django/utils/six.py", line 685, in reraise
    raise value.with_traceback(tb)
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/django/db/backends/utils.py", line 64, in execute
    return self.cursor.execute(sql, params)
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/elasticapm/instrumentation/packages/dbapi2.py", line 210, in execute
    return self._trace_sql(self.__wrapped__.execute, sql, params)
  File "/storage/.pyenv/versions/3.5.9/envs/squadrun_python3.5/lib/python3.5/site-packages/elasticapm/instrumentation/packages/dbapi2.py", line 244, in _trace_sql
    result = method(sql, params)
django.db.utils.OperationalError: canceling statement due to statement timeout

Sentry is attempting to send 0 pending error messages
Waiting up to 2 seconds
Press Ctrl-C to quit

超时SQL语句 #

ALTER TABLE "request_log_requestlog2" ADD COLUMN "request_type" smallint NULL CHECK ("request_type" >= 0)

问题原因 #

PostgreSQL执行ALTER TABLE ADD COLUMN时需要获取ACCESS EXCLUSIVE锁，这种锁会阻塞所有对表的读写操作。如果表处于持续高写入状态，锁请求会被正在执行的写操作阻塞，直到达到语句超时时间，最终导致迁移失败。

解决方案 #

1. 利用PostgreSQL 11+的轻量锁特性（推荐） #

PostgreSQL 11及以上版本添加无默认值的可空字段时，不需要重写全表，锁持有时间极短，理论上能瞬间完成。如果仍超时，大概率是存在长事务阻塞锁请求：

• 查询长事务：

SELECT pid, now() - pg_stat_activity.query_start AS duration, query, state
FROM pg_stat_activity
WHERE (now() - pg_stat_activity.query_start) > interval '5 minutes'
AND state = 'active';

• 确认后终止阻塞事务：

SELECT pg_terminate_backend(pid);

2. 自定义迁移，设置锁等待超时 #

修改迁移文件，手动设置锁等待超时，避免长时间阻塞：

from django.db import migrations, models

class Migration(migrations.Migration):
    dependencies = [
        ("request_log", "0004_requestlog2"),
    ]

    operations = [
        migrations.RunSQL(
            """
            SET lock_timeout = '10s'; -- 设置锁等待超时，超时后自动重试
            ALTER TABLE "request_log_requestlog2" ADD COLUMN "request_type" smallint NULL CHECK ("request_type" >= 0);
            """,
            reverse_sql="ALTER TABLE \"request_log_requestlog2\" DROP COLUMN \"request_type\";",
        ),
    ]

如果第一次执行超时，可多次尝试，直到锁请求成功获取。

3. 使用pg_repack工具无锁添加字段 #

如果以上方法无效，可使用pg_repack工具在线无锁重构表：

1. 安装对应PostgreSQL版本的pg_repack工具
2. 执行添加字段命令：

pg_repack -d 你的数据库名 -t request_log_requestlog2 --add-column="request_type smallint NULL CHECK (request_type >= 0)"

3. 让Django标记迁移已完成：

python manage.py migrate --fake request_log 0005_requestlog2_request_type

4. 低峰期执行迁移 #

如果业务允许，选择流量最低的时段执行迁移，此时表写入量大幅减少，锁请求更容易获取，超时概率降低。

内容的提问来源于stack exchange，提问作者Sagar Gupta