Re: DeadLocks..., DeadLocks...

From: Tom Allison <tom(at)tacocat(dot)net>
To: Gregory Stark <stark(at)enterprisedb(dot)com>
Cc: Bill Moran <wmoran(at)potentialtech(dot)com>, pgsql-general(at)postgresql(dot)org
Subject: Re: DeadLocks..., DeadLocks...
Date: 2007-06-15 00:14:24
Message-ID: 4671D9E0.2040607@tacocat.net
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-general

Gregory Stark wrote:
>
> I'm still not precisely clear what's going on, it might help if you posted the
> actual schema and the deadlock message which lists the precise locks that
> deadlocked.
>
> Are any of the DML you mention on other tables on those tables with foreign
> key references to this one?
>
> It's impossible for two inserts on the same table to deadlock against each
> other so there must be more going on than what you've described. It's hard to
> help much without a complete picture.
>

I think I found the problem. And it's not at all where I thought it was.
Process 17583 waits for ShareLock on transaction 306841;
blocked by process 17725.
Process 17725 waits for ShareLock on transaction 306840;
blocked by process 17583.

Where I'm at a lost is the deadlocks reported are on different tables.
However, getting back to the Foreign Key question
history_token does have a foreign key constraint on tokens.token_idx on delete
cascade.

So is the INSERT statement on history_token getting deadlocked by the token
UPDATE statement? Looks that way and the only think I can see causing that
might be a foreign key issue.

Am I correctly identifying the problem?
Any options?

2007-06-14 19:58:43 EDT 17725 306927 LOG: statement: select token_idx from
tokens where token in ('ShareLock','hdr:414A79FBC82','ht.history_idx','2271','hdr:
2007-06-14 19:58:31 EDT 17583 306840 LOG: statement: insert into
history_token(history_idx, token_idx)
select values.history_idx, values.token_idx
from ( values
(2862,260),(2862,31789),(2862,1518),(2862,59),(2862,555),(2862,4),(2862,66447),(2862,8178),(2862,64),(2862,132),(2862,6126),(2862,135),(2
862,69),(2862,9166),(2862,629),(2862,73),(2862,74),(2862,2271),(2862,78),(2862,493),(2862,8164),(2862,211),(2862,8166),(2862,84),(2862,60608),(2862,217),(2862,
88),(2862,8207),(2862,161),(2862,33518),(2862,220),(2862,222),(2862,446),(2862,2188),(2862,336),(2862,1197),(2862,166),(2862,1537),(2862,28),(2862,168),(2862,2
481),(2862,1081),(2862,99),(2862,100),(2862,172),(2862,8209),(2862,231),(2862,1900),(2862,344),(2862,104),(2862,24694),(2862,106),(2862,37),(2862,107),(2862,17
9),(2862,8203),(2862,99140),(2862,85629),(2862,3671),(2862,8187),(2862,187),(2862,306),(2862,254),(2862,415),(2862,256),(2862,257),(2862,99227),(2862,99228),(2
862,99229),(2862,99230) ) as values(history_idx, token_idx)
left outer join history_token ht using (history_idx, token_idx)
where ht.history_idx is null

2007-06-14 19:58:31 EDT 17725 306841 LOG: statement: update tokens set
last_seen = now() where token_idx in
(260,31789,1518,59,555,4,66447,8178,64,132,6126,13
5,69,9166,629,73,74,2271,78,493,8164,211,8166,84,99222,60608,217,88,8207,161,33518,220,222,446,2188,336,1197,166,1537,28,168,2481,1081,99,100,172,8209,231,1900
,344,104,24694,106,37,107,179,8203,99140,85629,3671,8187,187,306,254,415,256,257,99224,99225,99226)
2007-06-14 19:58:31 EDT 17657 306842 LOG: duration: 0.033 ms
2007-06-14 19:58:31 EDT 17657 306842 LOG: execute dbdpg_105: insert into
user_history(user_idx, history_idx, seen_as) values ($1,$2,'noscore')
2007-06-14 19:58:31 EDT 17657 306842 DETAIL: parameters: $1 = '1', $2 = '2853'
2007-06-14 19:58:31 EDT 17657 306842 LOG: duration: 0.194 ms
2007-06-14 19:58:32 EDT 17657 306843 LOG: statement: DEALLOCATE dbdpg_105
2007-06-14 19:58:32 EDT 17657 0 LOG: duration: 0.164 ms
2007-06-14 19:58:32 EDT 17657 306844 LOG: statement: select h_msgs, s_msgs from
user_token where user_idx = 1 and token_idx in (260,31789,1518,59,555,4,66447,
8178,64,132,6126,135,69,9166,629,73,74,2271,78,493,8164,211,8166,84,60608,217,88,8207,161,33518,220,222,446,2188,336,1197,166,1537,28,168,2481,1081,99,100,172,
8209,231,1900,344,104,24694,106,37,107,179,8203,99140,85629,3671,8187,187,306,254,415,256,257,99216,99217,99218,99219)
2007-06-14 19:58:32 EDT 17657 0 LOG: duration: 1.408 ms
2007-06-14 19:58:32 EDT 17657 306845 LOG: statement: update tokens set
last_seen = now() where token_idx in
(260,31789,1518,59,555,4,66447,8178,64,132,6126,13
5,69,9166,629,73,74,2271,78,493,8164,211,8166,84,60608,217,88,8207,161,33518,220,222,446,2188,336,1197,166,1537,28,168,2481,1081,99,100,172,8209,231,1900,344,1
04,24694,106,37,107,179,8203,99140,85629,3671,8187,187,306,254,415,256,257,99216,99217,99218,99219)
2007-06-14 19:58:33 EDT 17583 306840 ERROR: deadlock detected
2007-06-14 19:58:33 EDT 17583 306840 DETAIL: Process 17583 waits for ShareLock
on transaction 306841; blocked by process 17725.
Process 17725 waits for ShareLock on transaction 306840; blocked by
process 17583.
2007-06-14 19:58:33 EDT 17583 306840 CONTEXT: SQL statement "SELECT 1 FROM ONLY
"public"."tokens" x WHERE "token_idx" = $1 FOR SHARE OF x"
2007-06-14 19:58:33 EDT 17583 306840 STATEMENT: insert into
history_token(history_idx, token_idx)
select values.history_idx, values.token_idx
from ( values
(2862,260),(2862,31789),(2862,1518),(2862,59),(2862,555),(2862,4),(2862,66447),(2862,8178),(2862,64),(2862,132),(2862,6126),(2862,135),(2
862,69),(2862,9166),(2862,629),(2862,73),(2862,74),(2862,2271),(2862,78),(2862,493),(2862,8164),(2862,211),(2862,8166),(2862,84),(2862,60608),(2862,217),(2862,
88),(2862,8207),(2862,161),(2862,33518),(2862,220),(2862,222),(2862,446),(2862,2188),(2862,336),(2862,1197),(2862,166),(2862,1537),(2862,28),(2862,168),(2862,2
481),(2862,1081),(2862,99),(2862,100),(2862,172),(2862,8209),(2862,231),(2862,1900),(2862,344),(2862,104),(2862,24694),(2862,106),(2862,37),(2862,107),(2862,17
9),(2862,8203),(2862,99140),(2862,85629),(2862,3671),(2862,8187),(2862,187),(2862,306),(2862,254),(2862,415),(2862,256),(2862,257),(2862,99227),(2862,99228),(2
862,99229),(2862,99230) ) as values(history_idx, token_idx)
left outer join history_token ht using (history_idx, token_idx)
where ht.history_idx is null

2007-06-14 19:58:33 EDT 17725 0 LOG: duration: 1135.799 ms

In response to

Responses

Browse pgsql-general by date

  From Date Subject
Next Message Francisco Reyes 2007-06-15 00:15:03 Re: High-availability
Previous Message Francisco Reyes 2007-06-15 00:06:51 Re: pg_restore out of memory