一次服务升级时pg表DDL执行超时失败
# 背景
在一次业务升级过程中,需要针对 Postgresql 使用 DDL 对某个表新增一个字段,升级过程中失败了,报错信息如下:
ERROR: canceling statement due to lock tiemout
# 分析
DDL 在执行的时候需要拿到 ACCESS EXCLUSIVE 锁,而它是最强的表级锁,只有当表中没有任何活动的事务时才能拿到该锁。
查询 lock timeout 发现其设置为 2 分钟。
通过报错信息可以看到它获取锁失败了,所以我们大胆的猜测一下是有业务中有事务超过 2 分钟,从而导致 DDL 一直无法拿到锁。
通过下面的 SQL 来查询当前超过 2 分钟的活动查询,可以定位某条 SQL。
SELECT
pid,
now() - query_start AS duration,
state,
query,
application_name,
client_addr,
client_application_name,
xact_start,
query_start
FROM pg_stat_activity
WHERE state = 'active'
AND now() - query_start > interval '2 minutes'
AND pid <> pg_backend_pid() -- 排除当前查询自身
AND datname = 'your_database_name' -- 替换为你的数据库名
ORDER BY query_start;
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
最后找到了一条查询 SQL,查询时会拿 ACCESS SHARE 锁,所以其阻塞了 DDL 的执行。
这里做一个测试 postgresql 拿锁失败的测试。
使用 postgresql 客户端创建一个事务,对一个表进行查询,但是不关闭。
# begin;
BEGIN
# select * from apollo.task limit 1;
....
2
3
4
而后在另一个客户端针对该表中执行一个 DDL 语句,发现其超时了。
# ALTER TABLE apollo.task ADD COLUMN IF NOT EXISTS test int;
ERROR: canceling statement due to lock timeout
2
最后在第一个客户端中结束事务
# end;
COMMIT
2
再在第二个客户端再次执行 DDL 语句,显而易见的成功了。
# ALTER TABLE apollo.task ADD COLUMN IF NOT EXISTS test2 int;
ALTER TABLE
2
# 原因
现在我们通过该条 SQL 从业务代码中去找到执行的地方。
最后发现是在代码中使用了一个已经关闭的session,导致session 持续被打开而没有关闭,代码如下:
from sqlalchemy.orm.session import sessionmaker
_Session = sessionmaker()
@contextmanager
def open_session():
"""
通用psql的session上下文管理器
"""
try:
session = _Session()
yield session
session.commit()
except OperationalError as e:
logging.error(f"Postgresql connection error: {e}, track: {traceback.format_exc()}")
reconnection()
except Exception:
session.rollback()
raise
finally:
session.close()
with open_session() as session:
pass
task = TaskModel.get_by_id(session, task_id)
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
可以看到有使用一个上下文管理器来管理session的创建与关闭,而最后一行在 with 的作用域外面使用了 session,但是该session是在 with 结束时是调用了 session.close()
方法的。
通过查看 sqlalchemy 官网查询,即使是 close() 依然可能再次被使用。
https://docs.sqlalchemy.org/en/20/orm/session_api.html#sqlalchemy.orm.Session.close
也就是说,最后一行使用了 session 但是没有再次对其进行关闭,导致其持续活动,导致执行 DDL 无法获取到 ACCESS EXCLUSIVE 锁,最终超时失败。
# 结论
- 即使是被close()的对象不能再次被使用,有隐藏的风险。
- 使用完资源后,一定要记得关闭。