tortoise / tortoise/tortoise-orm

InterfaceError: the server expects 3 arguments for this query, 4 were passed

Open
#705 0 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

Dominant language
Python
Stars
5.6k
Forks
516
Avg merge
2d 21h
Merged PRs (30d)
9

Description

Describe the bug
Somehow sometimes parts of SQL from one transaction spills into another transaction

To Reproduce
We have two blocks of code (we are working on Discord bot)

First one:

async with in_transaction():
    await User.get_or_create(id=user_id)  # ensure that user is registered
    # select user 2nd time to lock it's row
    user = await User.filter(id=ctx.author.id).select_for_update(nowait=True).get(id=ctx.author.id)
    user.balance = F("balance") - lottery.ticket_price
    await user.save()

Second one:

async with in_transaction():
    await User.get_or_create(id=user_id)
    user = await User.filter(id=ctx.author.id).select_for_update(nowait=True).get(id=ctx.author.id)
    old_balance = user.balance
    user.balance = 0
    await user.save()

Usually, it works as expected (we are trying to prevent race conditions) but sometimes it just hangs out with CommandInvokeError exception

And here is the most interesting part!
When we print raw SQL during CommandInvokeError error we can see that parts of SQL code go from First code block to the second via some back magic...

What we got for the First one:

UPDATE "user"
SET    "balance"="balance"-10.00,
       "created_at"=$1,
       "modified_at"=$2
WHERE  "id"=$3: [Decimal('0'), datetime.datetime(2021, 4, 4, 21, 40, 35, 176201, tzinfo=), datetime.datetime(2021, 4, 7, 15, 23, 45, 64020, tzinfo=), 42424242424] 

What should be for the First one:

UPDATE "user"
SET    "balance"="balance"-10.00,
       "created_at"=$1,
       "modified_at"=$2
WHERE  "id"=$3: [datetime.datetime(2021, 4, 4, 21, 40, 35, 176201, tzinfo=), datetime.datetime(2021, 4, 7, 15, 23, 45, 64020, tzinfo=), 42424242424] 

What we got for the Second one:

UPDATE "user" SET "balance"=$1,"created_at"=$2,"modified_at"=$3 WHERE "id"=$4: [datetime.datetime(2021, 4, 7, 15, 30, 17, 150284, tzinfo=<UTC>), datetime.datetime(2021, 4, 7, 15, 33, 57, 23394, tzinfo=<UTC>), 454285372864724993]

What should be for the First one:

UPDATE "user" SET "balance"=$1,"created_at"=$2,"modified_at"=$3 WHERE "id"=$4: [Decimal('0'), datetime.datetime(2021, 4, 7, 15, 30, 17, 150284, tzinfo=<UTC>), datetime.datetime(2021, 4, 7, 15, 33, 57, 23394, tzinfo=<UTC>), 454285372864724993]

This bug randomly appears on the production, we can't reproduce it when we want.

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Start with the in_transaction blocks and the User.get_or_create, select_for_update, and save calls shown here; inspect how concurrent transactions construct and pass SQL parameters. Build a minimal concurrent reproduction of the intermittent argument-mixing failure. Done means identifying the transaction or parameter boundary and adding a regression test that no query receives another transaction's arguments.

Written by the indexing model from the issue text.

Assessment

Tech stack
postgresql, python
Domain
backend, database
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Needs clarification
Newbie friendliness
25/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.