Skip to content

UniqueViolationError raised when inserting user #168

@jchristgit

Description

@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.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions