- PVSM.RU - https://www.pvsm.ru -
Ситуация: есть высоконагруженная мета-игра для наших танков под названием Глобальная карта [1]. Эдакая пошаговая настолка для команд, где бои происходят в реальном танковом клиенте. В пиковые часы на карте несколько тысяч руководителей кланов производят игровые действия: атакуют друг друга, перемещают дивизии, покупают, продают, грабят корованы. Помимо этого, существует десяток сервисов, которые также могут вносить изменения в игровую ситуацию: подкидывают деньжат, штрафуют, добавляют игроков в клан и прочее.
Всё это неизбежно приводит к дэдлокам. Так вот, хочу вам поведать историю о том, как мы эти периодические проблемы держим в допустимых рамках.
Когда у нас возникает Deadlock, то падает исключение следующего вида:
ERROR: deadlock detected
DETAIL: Process 18293 waits for ShareLock on transaction 639; blocked by process 18254.
Process 18254 waits for ShareLock on transaction 640; blocked by process 18293.
HINT: See server log for query details.
CONTEXT: while updating tuple (0,9) in relation "users"
Первое, на что следует обратить внимание, — это строчка:
HINT: See server log for query details.
Действительно, если мы посмотрим серверные логи, то увидим для этого же места следующее:
ERROR: deadlock detected
И дальше конкретику:
DETAIL: Process 18293 waits for ShareLock on transaction 639; blocked by process 18254.
Process 18254 waits for ShareLock on transaction 640; blocked by process 18293.
Process 18293: update users set balance = balance + 10 where id = 2;
Process 18254: update users set balance = balance + 10 where id = 3;
HINT: See server log for query details.
CONTEXT: while updating tuple (0,9) in relation "users"
И, наконец, запрос, на котором произошла ошибка:
STATEMENT: update users set balance = balance + 10 where id = 2;
Логирование запросов при этом не обязано быть включено.
Круто. Но первая глобальная проблема для любого более-менее серьёзного проекта — то, что у вас нет доступа к серверным логам вследствие политики безопасности. Иногда вообще нет никакого доступа. А иногда можно попросить участок, но надо ждать. Иногда это 30 минут, иногда день.
А хотелось бы получать такую информацию сразу. В особенности, если у вас в проекте есть Sentry, и большинство ошибок команда разработки получает сразу.
Как-то подкрутить сервер, чтобы он такую информацию выдавал обычным клиентам — нельзя. Вследствие политики безопасности разработчиков базы. Но, если у вашего пользователя к базе доступ обычный, без всяких там ограничений на выполнения служебных функций и без Row-Level security policies [2], то организовать себе доступ к подобной информации всё же можно.
Мы можем преобразовать наши классы так, чтобы вручную получать похожую информацию. И даже больше. Для этого после отлова исключения о дэдлоке, нам необходимо:
SELECT * FROM pg_stat_activity;
from contextlib import contextmanager
from sqlalchemy import create_engine
from sqlalchemy.exc import OperationalError
engine = create_engine('postgresql+psycopg2://postgres:12345678@localhost/postgres')
def log_pg_stat_activity():
'''Log, write or send through Sentry pg_stat_activity'''
debug_conn = engine.connect()
for process in debug_conn.execute('''
SELECT pid, application_name, state, query FROM pg_stat_activity;
''').fetchall():
print(process)
@contextmanager
def connection():
conn = engine.connect()
try:
yield conn
except OperationalError as ex:
log_pg_stat_activity()
raise
@contextmanager
def transaction():
with connection() as conn:
with conn.begin() as trans:
try:
yield conn
except OperationalError as ex:
if 'deadlock detected' in ex.args[0]:
log_pg_stat_activity()
# Log exception
print(ex)
trans.rollback()
else:
raise
deadlock_test.py
from multiprocessing import Process
from time import sleep
from threading import Thread
from sqlalchemy.orm import sessionmaker
from db import transaction
def process1():
with transaction() as tran:
tran.execute('UPDATE users SET balance = balance + 10 WHERE id = 3;')
sleep(1)
tran.execute('UPDATE users SET balance = balance + 10 WHERE id = 1 RETURNING pg_sleep(1);')
def process2():
with transaction() as tran:
tran.execute('UPDATE users SET balance = balance + 10 WHERE id = 1;')
sleep(1)
tran.execute('UPDATE users SET balance = balance + 10 WHERE id = 3 RETURNING pg_sleep(1);')
if __name__ == '__main__':
p1 = Thread(target=process1)
p2 = Thread(target=process2)
p1.start()
p2.start()
sleep(4)
Или на github [3].
В данном случае у нас есть высокая вероятность того, что мы увидим какой именно запрос сломал нам транзакцию, вычислив его по PID и посмотрев текущий query.
Но бывает и так, что вычислив соединение по PID и посмотрев на query вы можете увидеть совсем не тот query, который устроил нам дедлок, а какой-нибудь следующий за ним по логике. Ведь пока вы ловили исключение и открывали соединение, нужный нам запрос для отлова мог и завершиться. Всё что мы можем здесь сделать — это работать через pgBouncer или его аналоги для минимизации времени установления соединения и использовать application_name.
Даже если вы получили тот запрос, который вызвал дедлок, у вас всё равно могут возникнуть трудности с пониманием, в каком месте логики он был вызван. И вот здесь на помощь приходит поле application_name. По умолчанию оно инициализируется не сильно полезной информацией, но его можно менять. А что если писать туда то место, откуда мы начинали транзакцию?
Сказано, сделано!
from traceback import extract_stack
@contextmanager
def transaction(application_name=None):
with connection() as conn:
if application_name is None:
caller = extract_stack()[-3]
conn.execution_options(autocommit=True).execute("SET application_name = %s", '%s:%s' % (caller[0], caller[1]))
with conn.begin() as trans:
try:
yield conn
except OperationalError as ex:
if 'deadlock detected' in ex.args[0]:
log_pg_stat_activity()
# Log exception
print(ex)
trans.rollback()
else:
raise
Или на github [4].
Вуаля. Теперь можно быстро открывать файлы в нужных местах и смотреть код.
pid | application_name | state | query | |
---|---|---|---|---|
1 | 8613 | deadlock_test.py:10 | idle in transaction (aborted) | UPDATE users SET balance = balance + 10 WHERE id = 1 RETURNING pg_sleep(1); |
2 | 8614 | deadlock_test.py:17 | active | UPDATE users SET balance = balance + 10 WHERE id = 3 RETURNING pg_sleep(1); |
3 | 8617 | active | SELECT pid, application_name, state, query FROM pg_stat_activity; |
Вся эта магия, описанная сверху хороша, но теоретически может не сработать. Иногда вам всё же не обойтись без серверных логов, поэтому необходимо сделать ещё два шага:
log_line_prefix = 'APP:%a PID:%p TR:%x '
.
Обычно в таких разделах дают ссылки на документацию об уровнях изоляции транзакций, видах блокировок и предлагают думать и анализировать в разрезе своего приложения. Я тоже так сделаю, но позже. А сначала просто опишу как мы это делаем чаще всего, ибо так уже получилось, что дедлоки у нас очень похожи друг на друга.
Самый наш частый случай следующий:
То есть имеем ситуацию, когда пришёл пяток результатов боёв, их обработка распараллелилась, при этом в параллельных процессах, бывает, встречаются одни и те же игроки.
Всё что тут можно сделать: или выстраивать начисления в цепочку, но это медленно, или позволять начислениям падать и пробовать начислить чуть позже.
У нас походовая игра. Раз в ход происходит пересчёт баланса игроков, учитывая большое количество совершённых ими игровых действий. На время изменения баланса мы блокировали другие изменения через SELECT… FOR UPDATE. Хотя мы блокировали не сразу всех, а чанками по 100, всё равно иногда уходили в дэдлок с процессом, который начисляет бонусы за бой, который не останавливается на время расчёта хода.
Так вот, оказалось, что мы были неправы. SELECT… FOR UPDATE — слишком мощная блокировка, необходимая только если выполняются 2 условия:
Возьмём пример:
--P1:
BEGIN;
--P2:
BEGIN;
--P1:
SELECT id FROM clans WHERE id=1 FOR UPDATE;
--P2:
INSERT INTO users(clan_id, name) VALUES(1, 'Alpha');
P2 в данной ситуации повиснет, поскольку мы даём СУБД понять, что запись с id=1 может перестать существовать. Однако в P1 мы не делаем ничего такого, только хотим защитить баланс клана от изменений. Поэтому, когда мы изменили FOR UPDATE на FOR NO KEY UPDATE, мы перестали ловить дэдлоки.
SELECT… FOR UPDATE в примере выше вызван явно. Но вы получите аналогичный эффект, если затронете своими изменениями уникальный ключ, на который ссылается внешний ключ из других таблиц. А любой UPDATE, который не затрагивает своими изменениями подобные ключи, вызовет блокировку аналогичную SELECT… FOR NO KEY UPDATE. Я вам рекомендую ознакомиться с этими особенностями в статье «Явные блокировки» в списке литературы ниже.
Вернёмся к ещё одной любопытной детали из первоначальной ошибки:
CONTEXT: while updating tuple (0,9) in relation "users"
Что за тупл спросите вы? Это физический адрес строчки в таблице, из-за которой возник конфликт. Дело в том, что в каждой таблице есть служебные поля, которые запросом SELECT * не выбираются. Однако стоит явно указать к примеру ctid среди полей, как мы увидим этот самый тупл:
SELECT ctid, id, nickname, balance FROM public.users;
Пользы от него немного в случае дедлока, ибо разблокированный процесс скорее всего обновит конфликтную строчку, и у неё изменится этот ctid (поскольку любой UPDATE в PostgreSQL на самом деле INSERT, а старая строчка помечается как невидимая и позже будет удалена автовакуумом). Но знать стоит, вдруг когда-нибудь пригодится.
Автор: Wargaming
Источник [11]
Сайт-источник PVSM.RU: https://www.pvsm.ru
Путь до страницы источника: https://www.pvsm.ru/python/260282
Ссылки в тексте:
[1] Глобальная карта: http://worldoftanks.ru/ru/clanwars/globalmap/
[2] Row-Level security policies: https://wiki.postgresql.org/wiki/What%27s_new_in_PostgreSQL_9.5#Row-Level_Security_Policies
[3] на github: https://github.com/gnomeby/postgresql-deadlock-test/tree/8acffd31f36d5a61560e17516d5b4cd0fe38695b
[4] на github: https://github.com/gnomeby/postgresql-deadlock-test/commit/d02a2e772c534111607ac187021176adb8c5d018
[5] Deadlocks in PostgreSQL: http://raghavt.blogspot.com.by/2011/11/deadlocks-in-postgresql.html
[6] Explicit locking: https://www.postgresql.org/docs/9.5/static/explicit-locking.html
[7] Явные блокировки: https://postgrespro.ru/docs/postgrespro/9.5/explicit-locking.html
[8] Lock Monitoring: https://wiki.postgresql.org/wiki/Lock_Monitoring
[9] System Columns: https://www.postgresql.org/docs/9.6/static/ddl-system-columns.html
[10] Introduction to PostgreSQL physical storage: http://rachbelaid.com/introduction-to-postgres-physical-storage/
[11] Источник: https://habrahabr.ru/post/323354/?utm_source=habrahabr&utm_medium=rss&utm_campaign=best
Нажмите здесь для печати.