UniqueViolationError raised when inserting user

[jchristgit]

A member update event triggered the following traceback shortly after startup:

2024-07-08 18:26:19 metricity-85d48b5747-9bpkj metricity.bot[16] ERROR Unhandled exception in on_member_update
Traceback (most recent call last):
    [ ... ]
  File "asyncpg/protocol/protocol.pyx", line 207, in bind_execute
asyncpg.exceptions.UniqueViolationError: duplicate key value violates unique constraint "users_pkey"
DETAIL:  Key (id)=(1234) already exists.

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

Traceback (most recent call last):
    [ ... ]
  File "/opt/poetry/cache/virtualenvs/metricity-KqPa2cfc-py3.12/lib/python3.12/site-packages/sqlalchemy/dialects/postgresql/asyncpg.py", line 784, in _handle_exception
    raise translated_error from error
sqlalchemy.dialects.postgresql.asyncpg.AsyncAdapt_asyncpg_dbapi.IntegrityError: <class 'asyncpg.exceptions.UniqueViolationError'>: duplicate key value violates unique constraint "users_pkey"
DETAIL:  Key (id)=(1234) already exists.

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

Traceback (most recent call last):
    [ ... ]
  File "/metricity/metricity/exts/event_listeners/member_listeners.py", line 125, in on_member_update
    await sess.commit()
    [ ... ]
  File "/opt/poetry/cache/virtualenvs/metricity-KqPa2cfc-py3.12/lib/python3.12/site-packages/sqlalchemy/dialects/postgresql/asyncpg.py", line 784, in _handle_exception
    raise translated_error from error
sqlalchemy.exc.IntegrityError: (sqlalchemy.dialects.postgresql.asyncpg.IntegrityError) <class 'asyncpg.exceptions.UniqueViolationError'>: duplicate key value violates unique constraint "users_pkey"
DETAIL:  Key (id)=(1234) already exists.
[SQL: INSERT INTO users (id, name, avatar_hash, guild_avatar_hash, joined_at, created_at, is_staff, bot, in_guild, public_flags, pending) VALUES ($1::VARCHAR, $2::VARCHAR, $3::VARCHAR, $4::VARCHAR, $5::TIMESTAMP WITHOUT TIME ZONE, $6::TIMESTAMP WITHOUT TIME ZONE, $7::BOOLEAN, $8::BOOLEAN, $9::BOOLEAN, $10::JSON, $11::BOOLEAN)]
[parameters: ('1234', 'redacted', 'redacted', None, datetime.datetime(2024, 7, 8, 18, 22, 50, 0), datetime.datetime(2020, 1, 1, 1, 1, 1, 0), False, False, True, '{"staff": false, "partner": false, "hypesquad": false, "bug_hunter": false, "hypesquad_bravery": false, "hypesquad_brilliance": false, "hypesquad_bal ... (127 characters truncated) ... , "verified_bot_developer": false, "discord_certified_moderator": false, "bot_http_interactions": false, "spammer": false, "active_developer": false}', False)]
(Background on this error at: https://sqlalche.me/e/20/gkpj)

Logs can currently be found via

kubectl logs -n bots metricity-85d48b5747-9bpkj --follow

This happened two seconds after the user sync was said to be complete. Of note is that the user join timestamp is four minutes before the log in question appeared.

Perhaps the sess.get(User, str(member.id)) call in on_member_update was performed before the user sync inserted it, then the coroutine didn't get scheduled back in time,

I think the proper fix here might be to switch to SERIALIZABLE transaction level. See https://blog.ydb.tech/do-we-fear-the-serializable-isolation-level-more-than-we-fear-subtle-bugs-5a025401b609 for some more information.