Обсуждение: Confusing deadlock report

Hello,

we have a strange (at least to me) deadlock situation which does not seem to fall into the "usual" deadlock category.

The error as reported in the Postgres log file is this:

2016-03-12 13:51:29.305 CET [23912]: [1-1] user=arthur,db=prod,app=[unknown] ERROR: deadlock detected
2016-03-12 13:51:29.305 CET [23912]: [2-1] user=arthur,db=prod,app=[unknown] DETAIL: Process 23912 waits for ShareLock
ontransaction; blocked by process 24342.  
        Process 24342 waits for ShareLock on transaction 39632974; blocked by process 23912.
        Process 23912: UPDATE alpha SET some_flag = $1 WHERE (id = $2)
        Process 24342: INSERT INTO bravo (..., alpha_id) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10)

(I have "obfuscated" the table names)


Process 24342 did update table alpha in an earlier step, but a different row than Process 23912 updated.
Table bravo has a foreign key to table alpha.

My understanding of the deadlock report is that the statements shown in the log are the actual statements on which the
twoprocesses were waiting.  

What I think is unusual in this situation is the INSERT statement that is part of the deadlock situation.

The only way I can think of how a deadlock could happen during an insert, is if process 23912 had inserted a row into
bravowith the same PK value that process 24342 is trying to insert. But process 23912 never even touches that table, so
Iam a bit confused on how this can happen.  

Can the foreign key between bravo and alpha play a role here? With some simple test setups I could not get the insert
towait even if it was referencing the row that the other process has updated.  

This happened on 9.3.10 running on Debian

The only changes I have found regarding "locks" or "deadlocks" after 9.3.10 is one change in 9.4.1 that says "Avoid
possibledeadlock while trying to acquire tuple locks in EvalPlanQual processing" - but I guess that does not refer to a
deadlockon "user level". 

Any ideas?
Thomas

Thomas Kellerer wrote:
> we have a strange (at least to me) deadlock situation which does not seem to fall into the "usual"
> deadlock category.
> 
> The error as reported in the Postgres log file is this:
> 
> 2016-03-12 13:51:29.305 CET [23912]: [1-1] user=arthur,db=prod,app=[unknown] ERROR: deadlock detected
> 2016-03-12 13:51:29.305 CET [23912]: [2-1] user=arthur,db=prod,app=[unknown] DETAIL: Process 23912
> waits for ShareLock on transaction; blocked by process 24342.
>         Process 24342 waits for ShareLock on transaction 39632974; blocked by process 23912.
>         Process 23912: UPDATE alpha SET some_flag = $1 WHERE (id = $2)
>         Process 24342: INSERT INTO bravo (..., alpha_id) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9,
> $10)
> 
> (I have "obfuscated" the table names)
> 
> 
> Process 24342 did update table alpha in an earlier step, but a different row than Process 23912
> updated.
> Table bravo has a foreign key to table alpha.
> 
> My understanding of the deadlock report is that the statements shown in the log are the actual
> statements on which the two processes were waiting.
> 
> What I think is unusual in this situation is the INSERT statement that is part of the deadlock
> situation.
> 
> The only way I can think of how a deadlock could happen during an insert, is if process 23912 had
> inserted a row into bravo with the same PK value that process 24342 is trying to insert. But process
> 23912 never even touches that table, so I am a bit confused on how this can happen.
> 
> Can the foreign key between bravo and alpha play a role here? With some simple test setups I could not
> get the insert to wait even if it was referencing the row that the other process has updated.
> 
> This happened on 9.3.10 running on Debian

The probable culprit is a foreign key between these tables.

What foreign keys are defined?

Yours,
Laurenz Albe

Albe Laurenz schrieb am 16.03.2016 um 13:20:
>> The error as reported in the Postgres log file is this:
>>
>> 2016-03-12 13:51:29.305 CET [23912]: [1-1] user=arthur,db=prod,app=[unknown] ERROR: deadlock detected
>> 2016-03-12 13:51:29.305 CET [23912]: [2-1] user=arthur,db=prod,app=[unknown] DETAIL: Process 23912
>> waits for ShareLock on transaction; blocked by process 24342.
>>         Process 24342 waits for ShareLock on transaction 39632974; blocked by process 23912.
>>         Process 23912: UPDATE alpha SET some_flag = $1 WHERE (id = $2)
>>         Process 24342: INSERT INTO bravo (..., alpha_id) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9,
>> $10)
>>
>> Can the foreign key between bravo and alpha play a role here? With some simple test setups I could not
>> get the insert to wait even if it was referencing the row that the other process has updated.
>>
>> This happened on 9.3.10 running on Debian
>
> The probable culprit is a foreign key between these tables.
>
> What foreign keys are defined?

The FK in question is:

   alter table bravo foreign key (alpha_id) references alpha (id);

But by simply creating two tables (with a foreign key) and doing an update in one transaction and the insert in
another,I do not get any locks or waiting transactions. 
(And to be honest: I would have been pretty disappointed if I had)

Thomas

Thomas Kellerer wrote:
>>> The error as reported in the Postgres log file is this:
>>>
>>> 2016-03-12 13:51:29.305 CET [23912]: [1-1] user=arthur,db=prod,app=[unknown] ERROR: deadlock detected
>>> 2016-03-12 13:51:29.305 CET [23912]: [2-1] user=arthur,db=prod,app=[unknown] DETAIL: Process 23912
>>> waits for ShareLock on transaction; blocked by process 24342.
>>>         Process 24342 waits for ShareLock on transaction 39632974; blocked by process 23912.
>>>         Process 23912: UPDATE alpha SET some_flag = $1 WHERE (id = $2)
>>>         Process 24342: INSERT INTO bravo (..., alpha_id) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9,
>>> $10)
>>>
>>> Can the foreign key between bravo and alpha play a role here? With some simple test setups I could not
>>> get the insert to wait even if it was referencing the row that the other process has updated.
>>>
>>> This happened on 9.3.10 running on Debian

>> The probable culprit is a foreign key between these tables.
>>
>> What foreign keys are defined?

> The FK in question is:
> 
>    alter table bravo foreign key (alpha_id) references alpha (id);
> 
> But by simply creating two tables (with a foreign key) and doing an update in one transaction and the
> insert in another, I do not get any locks or waiting transactions.
> (And to be honest: I would have been pretty disappointed if I had)

Hm, true; I cannot get a lock with these two statements.

Can you determine what statements were executed in these transactions before the deadlock?
It was probably one of these that took the conflicting lock.

Yours,
Laurenz Albe

Thomas Kellerer <spam_eater@gmx.net> writes:
> 2016-03-12 13:51:29.305 CET [23912]: [2-1] user=arthur,db=prod,app=[unknown] DETAIL: Process 23912 waits for
ShareLockon transaction; blocked by process 24342.  
>         Process 24342 waits for ShareLock on transaction 39632974; blocked by process 23912.
>         Process 23912: UPDATE alpha SET some_flag = $1 WHERE (id = $2)
>         Process 24342: INSERT INTO bravo (..., alpha_id) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10)

> Can the foreign key between bravo and alpha play a role here?

Absolutely.  The insert will need a sharelock on whatever alpha row the
new bravo row references.  Perhaps the newly-inserted row references some
row that 23912 previously updated (in the same transaction) while the
alpha row 23912 is currently trying to update was previously share-locked
by 24342 as a side effect of some previous insert?

            regards, tom lane

Albe Laurenz schrieb am 16.03.2016 um 14:38:
>>> waits for ShareLock on transaction; blocked by process 24342.
>>>>         Process 24342 waits for ShareLock on transaction 39632974; blocked by process 23912.
>>>>         Process 23912: UPDATE alpha SET some_flag = $1 WHERE (id = $2)
>>>>         Process 24342: INSERT INTO bravo (..., alpha_id) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9,
>>>> $10)
>>>>
>>>> Can the foreign key between bravo and alpha play a role here? With some simple test setups I could not
>>>> get the insert to wait even if it was referencing the row that the other process has updated.
>>>>
>>>> This happened on 9.3.10 running on Debian
>
>>> The probable culprit is a foreign key between these tables.
>>>
>>> What foreign keys are defined?
>
>> The FK in question is:
>>
>>    alter table bravo foreign key (alpha_id) references alpha (id);
>>
>> But by simply creating two tables (with a foreign key) and doing an update in one transaction and the
>> insert in another, I do not get any locks or waiting transactions.
>> (And to be honest: I would have been pretty disappointed if I had)
>
> Hm, true; I cannot get a lock with these two statements.
>
> Can you determine what statements were executed in these transactions before the deadlock?
> It was probably one of these that took the conflicting lock.

Unfortunately not. Statement logging is not enabled on that server (space-constrained).

And while we know the statements that can possibly be executed by these parts of the application, several on them
dependon the actual data, so it's hard to tell which path the two transactions actually used.  

Thomas

Tom Lane schrieb am 16.03.2016 um 14:45:
>> 2016-03-12 13:51:29.305 CET [23912]: [2-1] user=arthur,db=prod,app=[unknown] DETAIL: Process 23912 waits for
ShareLockon transaction; blocked by process 24342.  
>>         Process 24342 waits for ShareLock on transaction 39632974; blocked by process 23912.
>>         Process 23912: UPDATE alpha SET some_flag = $1 WHERE (id = $2)
>>         Process 24342: INSERT INTO bravo (..., alpha_id) VALUES ($1, $2, $3, $4, $5, $6, $7, $8, $9, $10)
>
>> Can the foreign key between bravo and alpha play a role here?
>
> Absolutely.  The insert will need a sharelock on whatever alpha row the
> new bravo row references.  Perhaps the newly-inserted row references some
> row that 23912 previously updated (in the same transaction) while the
> alpha row 23912 is currently trying to update was previously share-locked
> by 24342 as a side effect of some previous insert?

Hmm, I tried a very simple setup like this:

  create table master (id integer primary key, data text);
  create table child (id integer primary key, master_id integer not null references master on update set null);

  insert into master (id, data)
   values
  (1,'one'),
  (2,'two'),
  (3,'three');

then in one transaction I do:

  update master
    set data = 'bar'
  where id = 1;

and in a second transaction I run:

  insert into child
    (id, master_id)
  values
    (1, 1);

But the second transaction does not wait for the UPDATE to finish.
So I guess it must be a bit more complicated then that.

Thomas

Thomas Kellerer wrote:
>> Can you determine what statements were executed in these transactions before the deadlock?
>> It was probably one of these that took the conflicting lock.
> 
> Unfortunately not. Statement logging is not enabled on that server (space-constrained).
> 
> And while we know the statements that can possibly be executed by these parts of the application,
> several on them depend on the actual data, so it's hard to tell which path the two transactions
> actually used.

But that's where the solution to your problem must be...

Look at all statements that modify "alpha" and could be in the same transaction
with the INSERT to "bravo".

Yours,
Laurenz Albe