pg.ddx.io  pgsql-hackers@postgresql.org mailing list archive  
help / color / mirror / Atom feed
undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
23+ messages / 3 participants
[nested] [flat]

Commits from this thread:
  2023-12-11 e81e617f32 b47ea4f3d3 3f86867d56 332b430633 01cc92fa62 8d7d2197f3  Fix an undetected deadlock due to apply worker.
* undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-11-21 11:47  Tomas Vondra <tomas.vondra@enterprisedb.com>
  0 siblings, 1 reply; 23+ messages in thread

From: Tomas Vondra @ 2023-11-21 11:47 UTC (permalink / raw)
  To: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

Hi,

I decided to do some stress-testing of the built-in logical replication,
as part of the sequence decoding work. And I soon ran into an undetected
deadlock related to ALTER SUBSCRIPTION ... REFRESH PUBLICATION :-(

The attached bash scripts triggers that in a couple seconds for me. The
script looks complicated, but most of the code is waiting for sync to
complete, catchup, and that sort of thing.

What the script does is pretty simple:

1) initialize two clusters, set them as publisher/subscriber pair

2) create some number of tables, add them to publication and wait for
   the sync to complete

3) start two pgbench runs in the background, modifying the publication
   (one removes+adds all tables in a single transaction, one does that
    with transaction per table)

4) run refresh.sh which does ALTER PUBLICATION ... REFRESH PUBLICATION
   in a loop (now that I think about it, could be another pgbench
   script, but well ...)

5) some consistency checks, but the lockup happens earlier so this does
   not really matter

After a small number of refresh cycles (for me it's usually a couple
dozen), we end up with a couple stuck locks (I shortened the backend
type string a bit, for formatting reasons):

  test=# select a.pid, classid, objid, backend_type, query
           from pg_locks l join pg_stat_activity a on (a.pid = l.pid)
          where not granted;

     pid   | classid | objid | backend_type     |         query
  ---------+---------+-------+------------------+----------------------
   2691941 |    6100 | 16785 | client backend   | ALTER SUBSCRIPTION s
                                                  REFRESH PUBLICATION
   2691837 |    6100 | 16785 | tablesync worker |
   2691936 |    6100 | 16785 | tablesync worker |
  (3 rows)

All these backends wait for 6100/16785, which is the subscription row in
pg_subscription. The tablesync workers are requesting AccessShareLock,
the client backend however asks for AccessExclusiveLock.

The entry is currently locked by:

  test=# select a.pid, mode, backend_type from pg_locks l
           join pg_stat_activity a on (a.pid = l.pid)
          where classid=6100 and objid=16785 and granted;

     pid   |      mode       |           backend_type
  ---------+-----------------+----------------------------------
   2690477 | AccessShareLock | logical replication apply worker
  (1 row)

But the apply worker is not waiting for any locks, so what's going on?

Well, the problem is the apply worker is waiting for notification from
the tablesync workers the relation is synced, which happens through
updating the pg_subscription_rel row. And that wait happens in
wait_for_relation_state_change, which simply checks the row in a loop,
with a sleep by WaitLatch().

Unfortunately, the tablesync workers can't update the row because the
client backend executing ALTER SUBSCRIPTION ... REFRESH PUBLICATION
sneaked in, and waits for an AccessExclusiveLock. So the tablesync
workers are stuck in the queue and can't proceed.

The client backend can't proceed, because it's waiting for a lock held
by the apply worker.

The tablesync workers can't proceed because their lock request is stuck
behind the AccessExclusiveLock request.

And the apply worker can't proceed, because it's waiting for status
update from the tablesync workers.

And the deadlock is undetected, because the apply worker is not waiting
on a lock, but sleeping on a latch :-(


I don't know what's the right solution here. I wonder if the apply
worker might release the lock before waiting for the update, that'd
solve this whole issue.

Alternatively, ALTER PUBLICATION might wait for the lock only for a
limited amount of time, and try again (but then it'd be susceptible to
starving, of course).

Or maybe there's a way to make this work in a way that would be visible
to the deadlock detector? That'd mean we occasionally get processes
killed to resolve a deadlock, but that's still better than processes
stuck indefinitely ...


regards

-- 
Tomas Vondra
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

Attachments:

  lockup-test.sh (application/x-shellscript, 9.3K) download

  refresh.sh (application/x-shellscript, 466B) download

^ permalink  raw  reply  [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-11-21 13:16  Amit Kapila <amit.kapila16@gmail.com>
  parent: Tomas Vondra <tomas.vondra@enterprisedb.com>
  0 siblings, 1 reply; 23+ messages in thread

From: Amit Kapila @ 2023-11-21 13:16 UTC (permalink / raw)
  To: Tomas Vondra <tomas.vondra@enterprisedb.com>; +Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On Tue, Nov 21, 2023 at 5:17 PM Tomas Vondra
<tomas.vondra@enterprisedb.com> wrote:
>
> I decided to do some stress-testing of the built-in logical replication,
> as part of the sequence decoding work. And I soon ran into an undetected
> deadlock related to ALTER SUBSCRIPTION ... REFRESH PUBLICATION :-(
>
> The attached bash scripts triggers that in a couple seconds for me. The
> script looks complicated, but most of the code is waiting for sync to
> complete, catchup, and that sort of thing.
>
> What the script does is pretty simple:
>
> 1) initialize two clusters, set them as publisher/subscriber pair
>
> 2) create some number of tables, add them to publication and wait for
>    the sync to complete
>
> 3) start two pgbench runs in the background, modifying the publication
>    (one removes+adds all tables in a single transaction, one does that
>     with transaction per table)
>
> 4) run refresh.sh which does ALTER PUBLICATION ... REFRESH PUBLICATION
>    in a loop (now that I think about it, could be another pgbench
>    script, but well ...)
>
> 5) some consistency checks, but the lockup happens earlier so this does
>    not really matter
>
> After a small number of refresh cycles (for me it's usually a couple
> dozen), we end up with a couple stuck locks (I shortened the backend
> type string a bit, for formatting reasons):
>
>   test=# select a.pid, classid, objid, backend_type, query
>            from pg_locks l join pg_stat_activity a on (a.pid = l.pid)
>           where not granted;
>
>      pid   | classid | objid | backend_type     |         query
>   ---------+---------+-------+------------------+----------------------
>    2691941 |    6100 | 16785 | client backend   | ALTER SUBSCRIPTION s
>                                                   REFRESH PUBLICATION
>    2691837 |    6100 | 16785 | tablesync worker |
>    2691936 |    6100 | 16785 | tablesync worker |
>   (3 rows)
>
> All these backends wait for 6100/16785, which is the subscription row in
> pg_subscription. The tablesync workers are requesting AccessShareLock,
> the client backend however asks for AccessExclusiveLock.
>
> The entry is currently locked by:
>
>   test=# select a.pid, mode, backend_type from pg_locks l
>            join pg_stat_activity a on (a.pid = l.pid)
>           where classid=6100 and objid=16785 and granted;
>
>      pid   |      mode       |           backend_type
>   ---------+-----------------+----------------------------------
>    2690477 | AccessShareLock | logical replication apply worker
>   (1 row)
>
> But the apply worker is not waiting for any locks, so what's going on?
>
> Well, the problem is the apply worker is waiting for notification from
> the tablesync workers the relation is synced, which happens through
> updating the pg_subscription_rel row. And that wait happens in
> wait_for_relation_state_change, which simply checks the row in a loop,
> with a sleep by WaitLatch().
>
> Unfortunately, the tablesync workers can't update the row because the
> client backend executing ALTER SUBSCRIPTION ... REFRESH PUBLICATION
> sneaked in, and waits for an AccessExclusiveLock. So the tablesync
> workers are stuck in the queue and can't proceed.
>
> The client backend can't proceed, because it's waiting for a lock held
> by the apply worker.
>

It seems there is some inconsistency in what you have written for
client backends/tablesync worker vs. apply worker. The above text
seems to be saying that the client backend and table sync worker are
waiting on a "subscription row in pg_subscription" and the apply
worker is operating on "pg_subscription_rel". So, if that is true then
they shouldn't get stuck.

I think here client backend and tablesync worker seems to be blocked
for a lock on pg_subscription_rel.

> The tablesync workers can't proceed because their lock request is stuck
> behind the AccessExclusiveLock request.
>
> And the apply worker can't proceed, because it's waiting for status
> update from the tablesync workers.
>

This part is not clear to me because
wait_for_relation_state_change()->GetSubscriptionRelState() seems to
be releasing the lock while closing the relation. Am, I missing
something?

-- 
With Regards,
Amit Kapila.





^ permalink  raw  reply  [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-11-21 13:26  Tomas Vondra <tomas.vondra@enterprisedb.com>
  parent: Amit Kapila <amit.kapila16@gmail.com>
  0 siblings, 1 reply; 23+ messages in thread

From: Tomas Vondra @ 2023-11-21 13:26 UTC (permalink / raw)
  To: Amit Kapila <amit.kapila16@gmail.com>; +Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>



On 11/21/23 14:16, Amit Kapila wrote:
> On Tue, Nov 21, 2023 at 5:17 PM Tomas Vondra
> <tomas.vondra@enterprisedb.com> wrote:
>>
>> I decided to do some stress-testing of the built-in logical replication,
>> as part of the sequence decoding work. And I soon ran into an undetected
>> deadlock related to ALTER SUBSCRIPTION ... REFRESH PUBLICATION :-(
>>
>> The attached bash scripts triggers that in a couple seconds for me. The
>> script looks complicated, but most of the code is waiting for sync to
>> complete, catchup, and that sort of thing.
>>
>> What the script does is pretty simple:
>>
>> 1) initialize two clusters, set them as publisher/subscriber pair
>>
>> 2) create some number of tables, add them to publication and wait for
>>    the sync to complete
>>
>> 3) start two pgbench runs in the background, modifying the publication
>>    (one removes+adds all tables in a single transaction, one does that
>>     with transaction per table)
>>
>> 4) run refresh.sh which does ALTER PUBLICATION ... REFRESH PUBLICATION
>>    in a loop (now that I think about it, could be another pgbench
>>    script, but well ...)
>>
>> 5) some consistency checks, but the lockup happens earlier so this does
>>    not really matter
>>
>> After a small number of refresh cycles (for me it's usually a couple
>> dozen), we end up with a couple stuck locks (I shortened the backend
>> type string a bit, for formatting reasons):
>>
>>   test=# select a.pid, classid, objid, backend_type, query
>>            from pg_locks l join pg_stat_activity a on (a.pid = l.pid)
>>           where not granted;
>>
>>      pid   | classid | objid | backend_type     |         query
>>   ---------+---------+-------+------------------+----------------------
>>    2691941 |    6100 | 16785 | client backend   | ALTER SUBSCRIPTION s
>>                                                   REFRESH PUBLICATION
>>    2691837 |    6100 | 16785 | tablesync worker |
>>    2691936 |    6100 | 16785 | tablesync worker |
>>   (3 rows)
>>
>> All these backends wait for 6100/16785, which is the subscription row in
>> pg_subscription. The tablesync workers are requesting AccessShareLock,
>> the client backend however asks for AccessExclusiveLock.
>>
>> The entry is currently locked by:
>>
>>   test=# select a.pid, mode, backend_type from pg_locks l
>>            join pg_stat_activity a on (a.pid = l.pid)
>>           where classid=6100 and objid=16785 and granted;
>>
>>      pid   |      mode       |           backend_type
>>   ---------+-----------------+----------------------------------
>>    2690477 | AccessShareLock | logical replication apply worker
>>   (1 row)
>>
>> But the apply worker is not waiting for any locks, so what's going on?
>>
>> Well, the problem is the apply worker is waiting for notification from
>> the tablesync workers the relation is synced, which happens through
>> updating the pg_subscription_rel row. And that wait happens in
>> wait_for_relation_state_change, which simply checks the row in a loop,
>> with a sleep by WaitLatch().
>>
>> Unfortunately, the tablesync workers can't update the row because the
>> client backend executing ALTER SUBSCRIPTION ... REFRESH PUBLICATION
>> sneaked in, and waits for an AccessExclusiveLock. So the tablesync
>> workers are stuck in the queue and can't proceed.
>>
>> The client backend can't proceed, because it's waiting for a lock held
>> by the apply worker.
>>
> 
> It seems there is some inconsistency in what you have written for
> client backends/tablesync worker vs. apply worker. The above text
> seems to be saying that the client backend and table sync worker are
> waiting on a "subscription row in pg_subscription" and the apply
> worker is operating on "pg_subscription_rel". So, if that is true then
> they shouldn't get stuck.
> 
> I think here client backend and tablesync worker seems to be blocked
> for a lock on pg_subscription_rel.
> 

Not really, they are all locking the subscription. All the locks are on
classid=6100, which is pg_subscription:

  test=# select 6100::regclass;
      regclass
  -----------------
   pg_subscription
  (1 row)

The thing is, the tablesync workers call UpdateSubscriptionRelState,
which locks the pg_subscription catalog at the very beginning:

   LockSharedObject(SubscriptionRelationId, ...);

So that's the issue. I haven't explored why it's done this way, and
there's no comment explaining locking the subscriptions is needed ...

>> The tablesync workers can't proceed because their lock request is stuck
>> behind the AccessExclusiveLock request.
>>
>> And the apply worker can't proceed, because it's waiting for status
>> update from the tablesync workers.
>>
> 
> This part is not clear to me because
> wait_for_relation_state_change()->GetSubscriptionRelState() seems to
> be releasing the lock while closing the relation. Am, I missing
> something?
> 

I think you're missing the fact that GetSubscriptionRelState() acquires
and releases the lock on pg_subscription_rel, but that's not the lock
causing the issue. The problem is the lock on the pg_subscription row.

regards

-- 
Tomas Vondra
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company





^ permalink  raw  reply  [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-11-22 10:38  Amit Kapila <amit.kapila16@gmail.com>
  parent: Tomas Vondra <tomas.vondra@enterprisedb.com>
  0 siblings, 1 reply; 23+ messages in thread

From: Amit Kapila @ 2023-11-22 10:38 UTC (permalink / raw)
  To: Tomas Vondra <tomas.vondra@enterprisedb.com>; +Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On Tue, Nov 21, 2023 at 6:56 PM Tomas Vondra
<tomas.vondra@enterprisedb.com> wrote:
>
> On 11/21/23 14:16, Amit Kapila wrote:
> > On Tue, Nov 21, 2023 at 5:17 PM Tomas Vondra
> > <tomas.vondra@enterprisedb.com> wrote:
> >>
> >
> > It seems there is some inconsistency in what you have written for
> > client backends/tablesync worker vs. apply worker. The above text
> > seems to be saying that the client backend and table sync worker are
> > waiting on a "subscription row in pg_subscription" and the apply
> > worker is operating on "pg_subscription_rel". So, if that is true then
> > they shouldn't get stuck.
> >
> > I think here client backend and tablesync worker seems to be blocked
> > for a lock on pg_subscription_rel.
> >
>
> Not really, they are all locking the subscription. All the locks are on
> classid=6100, which is pg_subscription:
>
>   test=# select 6100::regclass;
>       regclass
>   -----------------
>    pg_subscription
>   (1 row)
>
> The thing is, the tablesync workers call UpdateSubscriptionRelState,
> which locks the pg_subscription catalog at the very beginning:
>
>    LockSharedObject(SubscriptionRelationId, ...);
>
> So that's the issue. I haven't explored why it's done this way, and
> there's no comment explaining locking the subscriptions is needed ...
>

I think it prevents concurrent drop of rel during the REFRESH operation.

> >> The tablesync workers can't proceed because their lock request is stuck
> >> behind the AccessExclusiveLock request.
> >>
> >> And the apply worker can't proceed, because it's waiting for status
> >> update from the tablesync workers.
> >>
> >
> > This part is not clear to me because
> > wait_for_relation_state_change()->GetSubscriptionRelState() seems to
> > be releasing the lock while closing the relation. Am, I missing
> > something?
> >
>
> I think you're missing the fact that GetSubscriptionRelState() acquires
> and releases the lock on pg_subscription_rel, but that's not the lock
> causing the issue. The problem is the lock on the pg_subscription row.
>

Okay. IIUC, what's going on here is that the apply worker acquires
AccessShareLock on pg_subscription to update rel state for one of the
tables say tbl-1, and then for another table say tbl-2, it started
waiting for a state change via wait_for_relation_state_change(). I
think here the fix is to commit the transaction before we go for a
wait. I guess we need something along the lines of what is proposed in
[1] though we have solved the problem in that thread in some other
way..

[1] - https://www.postgresql.org/message-id/1412708.1674417574%40sss.pgh.pa.us

-- 
With Regards,
Amit Kapila.





^ permalink  raw  reply  [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-11-22 11:21  Tomas Vondra <tomas.vondra@enterprisedb.com>
  parent: Amit Kapila <amit.kapila16@gmail.com>
  0 siblings, 1 reply; 23+ messages in thread

From: Tomas Vondra @ 2023-11-22 11:21 UTC (permalink / raw)
  To: Amit Kapila <amit.kapila16@gmail.com>; +Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On 11/22/23 11:38, Amit Kapila wrote:
> On Tue, Nov 21, 2023 at 6:56 PM Tomas Vondra
> <tomas.vondra@enterprisedb.com> wrote:
>>
>> On 11/21/23 14:16, Amit Kapila wrote:
>>> On Tue, Nov 21, 2023 at 5:17 PM Tomas Vondra
>>> <tomas.vondra@enterprisedb.com> wrote:
>>>>
>>>
>>> It seems there is some inconsistency in what you have written for
>>> client backends/tablesync worker vs. apply worker. The above text
>>> seems to be saying that the client backend and table sync worker are
>>> waiting on a "subscription row in pg_subscription" and the apply
>>> worker is operating on "pg_subscription_rel". So, if that is true then
>>> they shouldn't get stuck.
>>>
>>> I think here client backend and tablesync worker seems to be blocked
>>> for a lock on pg_subscription_rel.
>>>
>>
>> Not really, they are all locking the subscription. All the locks are on
>> classid=6100, which is pg_subscription:
>>
>>   test=# select 6100::regclass;
>>       regclass
>>   -----------------
>>    pg_subscription
>>   (1 row)
>>
>> The thing is, the tablesync workers call UpdateSubscriptionRelState,
>> which locks the pg_subscription catalog at the very beginning:
>>
>>    LockSharedObject(SubscriptionRelationId, ...);
>>
>> So that's the issue. I haven't explored why it's done this way, and
>> there's no comment explaining locking the subscriptions is needed ...
>>
> 
> I think it prevents concurrent drop of rel during the REFRESH operation.
> 

Yes. Or maybe some other concurrent DDL on the relations included in the
subscription.

>>>> The tablesync workers can't proceed because their lock request is stuck
>>>> behind the AccessExclusiveLock request.
>>>>
>>>> And the apply worker can't proceed, because it's waiting for status
>>>> update from the tablesync workers.
>>>>
>>>
>>> This part is not clear to me because
>>> wait_for_relation_state_change()->GetSubscriptionRelState() seems to
>>> be releasing the lock while closing the relation. Am, I missing
>>> something?
>>>
>>
>> I think you're missing the fact that GetSubscriptionRelState() acquires
>> and releases the lock on pg_subscription_rel, but that's not the lock
>> causing the issue. The problem is the lock on the pg_subscription row.
>>
> 
> Okay. IIUC, what's going on here is that the apply worker acquires
> AccessShareLock on pg_subscription to update rel state for one of the
> tables say tbl-1, and then for another table say tbl-2, it started
> waiting for a state change via wait_for_relation_state_change(). I
> think here the fix is to commit the transaction before we go for a
> wait. I guess we need something along the lines of what is proposed in
> [1] though we have solved the problem in that thread in some other
> way..
> 

Possibly. I haven't checked if the commit might have some unexpected
consequences, but I can confirm I can no longer reproduce the deadlock
with the patch applied.


regards

-- 
Tomas Vondra
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company





^ permalink  raw  reply  [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-11-23 09:24  Amit Kapila <amit.kapila16@gmail.com>
  parent: Tomas Vondra <tomas.vondra@enterprisedb.com>
  0 siblings, 1 reply; 23+ messages in thread

From: Amit Kapila @ 2023-11-23 09:24 UTC (permalink / raw)
  To: Tomas Vondra <tomas.vondra@enterprisedb.com>; +Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On Wed, Nov 22, 2023 at 4:51 PM Tomas Vondra
<tomas.vondra@enterprisedb.com> wrote:
>
> On 11/22/23 11:38, Amit Kapila wrote:
> >
> > Okay. IIUC, what's going on here is that the apply worker acquires
> > AccessShareLock on pg_subscription to update rel state for one of the
> > tables say tbl-1, and then for another table say tbl-2, it started
> > waiting for a state change via wait_for_relation_state_change(). I
> > think here the fix is to commit the transaction before we go for a
> > wait. I guess we need something along the lines of what is proposed in
> > [1] though we have solved the problem in that thread in some other
> > way..
> >
>
> Possibly. I haven't checked if the commit might have some unexpected
> consequences, but I can confirm I can no longer reproduce the deadlock
> with the patch applied.
>

Thanks for the verification. Offhand, I don't see any problem with
doing a commit at that place but will try to think some more about it.
I think we may want to call pgstat_report_stat(false) after commit to
avoid a long delay in stats.

I haven't verified but I think this will be a problem in back-branches as well.

-- 
With Regards,
Amit Kapila.





^ permalink  raw  reply  [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-11-23 16:45  Tomas Vondra <tomas.vondra@enterprisedb.com>
  parent: Amit Kapila <amit.kapila16@gmail.com>
  0 siblings, 1 reply; 23+ messages in thread

From: Tomas Vondra @ 2023-11-23 16:45 UTC (permalink / raw)
  To: Amit Kapila <amit.kapila16@gmail.com>; +Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>


On 11/23/23 10:24, Amit Kapila wrote:
> On Wed, Nov 22, 2023 at 4:51 PM Tomas Vondra
> <tomas.vondra@enterprisedb.com> wrote:
>>
>> On 11/22/23 11:38, Amit Kapila wrote:
>>>
>>> Okay. IIUC, what's going on here is that the apply worker acquires
>>> AccessShareLock on pg_subscription to update rel state for one of the
>>> tables say tbl-1, and then for another table say tbl-2, it started
>>> waiting for a state change via wait_for_relation_state_change(). I
>>> think here the fix is to commit the transaction before we go for a
>>> wait. I guess we need something along the lines of what is proposed in
>>> [1] though we have solved the problem in that thread in some other
>>> way..
>>>
>>
>> Possibly. I haven't checked if the commit might have some unexpected
>> consequences, but I can confirm I can no longer reproduce the deadlock
>> with the patch applied.
>>
> 
> Thanks for the verification. Offhand, I don't see any problem with
> doing a commit at that place but will try to think some more about it.
> I think we may want to call pgstat_report_stat(false) after commit to
> avoid a long delay in stats.
> 

Makes sense.

> I haven't verified but I think this will be a problem in
> back-branches as well.
> 

Yes. I haven't tried but I don't see why backbranches wouldn't have the
same issue.

regards

-- 
Tomas Vondra
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company





^ permalink  raw  reply  [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-11-24 04:15  Shlok Kyal <shlok.kyal.oss@gmail.com>
  parent: Tomas Vondra <tomas.vondra@enterprisedb.com>
  0 siblings, 1 reply; 23+ messages in thread

From: Shlok Kyal @ 2023-11-24 04:15 UTC (permalink / raw)
  To: Tomas Vondra <tomas.vondra@enterprisedb.com>; +Cc: Amit Kapila <amit.kapila16@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

Hi,

I tried to reproduce the issue and was able to reproduce it with
scripts shared by Tomas.
I tried testing it from PG17 to PG 11. This issue is reproducible for
each version.

Next I would try to test with the patch in the thread shared by Amit.

Thanks,
Shlok Kumar Kyal





^ permalink  raw  reply  [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-11-24 11:35  Shlok Kyal <shlok.kyal.oss@gmail.com>
  parent: Shlok Kyal <shlok.kyal.oss@gmail.com>
  0 siblings, 1 reply; 23+ messages in thread

From: Shlok Kyal @ 2023-11-24 11:35 UTC (permalink / raw)
  To: Tomas Vondra <tomas.vondra@enterprisedb.com>; +Cc: Amit Kapila <amit.kapila16@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

Hi,

> I tried to reproduce the issue and was able to reproduce it with
> scripts shared by Tomas.
> I tried testing it from PG17 to PG 11. This issue is reproducible for
> each version.
>
> Next I would try to test with the patch in the thread shared by Amit.

I have created the v1 patch to resolve the issue. Have tested the
patch on HEAD to PG12.
The same patch applies to all the versions. The changes are similar to
the one posted in the thread
https://www.postgresql.org/message-id/1412708.1674417574%40sss.pgh.pa.us

Thanks and Regards,
Shlok Kyal

Attachments:

v1-0001-Deadlock-when-apply-worker-tablesync-worker-and-c.patch (application/octet-stream, 2.7K) download From 549ebeac998a0f81d0b2a99191db84e153dcc582 Mon Sep 17 00:00:00 2001 From: Shlok Kyal <shlok.kyal.oss@gmail.com> Date: Fri, 24 Nov 2023 16:37:14 +0530 Subject: [PATCH v1] Deadlock when apply worker,tablesync worker and client backend run parallelly. Apply worker holds a lock on the table pg_subscription_rel and waits for notification from the tablesync workers where the relation is synced, which happens through updating the pg_subscription_rel row. And that wait happens in wait_for_relation_state_change, which simply checks the row in a loop, with a sleep by WaitLatch(). Unfortunately, the tablesync workers can't update the row because the client backend executing ALTER SUBSCRIPTION ... REFRESH PUBLICATION sneaked in, and waits for an AccessExclusiveLock. So the tablesync workers are stuck in the queue and can't proceed. The client backend is waiting for a lock held by the apply worker. The tablesync workers can't proceed because their lock request is stuck behind the AccessExclusiveLock request. And the apply worker is waiting for status update from the tablesync workers. And the deadlock is undetected, because the apply worker is not waiting on a lock, but sleeping on a latch. We have resolved the issue by releasing the lock by commiting the transaction before the apply worker goes to wait state. --- src/backend/replication/logical/tablesync.c | 19 ++++++++++++++++--- 1 file changed, 16 insertions(+), 3 deletions(-) diff --git a/src/backend/replication/logical/tablesync.c b/src/backend/replication/logical/tablesync.c index df3c42eb5d..e2b3ce64cb 100644 --- a/src/backend/replication/logical/tablesync.c +++ b/src/backend/replication/logical/tablesync.c @@ -542,15 +542,28 @@ process_syncing_tables_for_apply(XLogRecPtr current_lsn) LWLockRelease(LogicalRepWorkerLock); /* - * Enter busy loop and wait for synchronization worker to - * reach expected state (or die trying). + * If we have a transaction, we must commit it to release + * any locks we have (it's quite likely we hold lock on + * pg_replication_origin, which the sync worker will need + * to update). Then start a new transaction so we can + * examine catalog state. */ - if (!started_tx) + if (started_tx) + { + CommitTransactionCommand(); + pgstat_report_stat(false); + StartTransactionCommand(); + } + else { StartTransactionCommand(); started_tx = true; } + /* + * Enter busy loop and wait for synchronization worker to + * reach expected state (or die trying). + */ wait_for_relation_state_change(rstate->relid, SUBREL_STATE_SYNCDONE); } -- 2.34.1
^ permalink raw reply [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-11-25 11:05  Amit Kapila <amit.kapila16@gmail.com>
  parent: Shlok Kyal <shlok.kyal.oss@gmail.com>
  0 siblings, 1 reply; 23+ messages in thread

From: Amit Kapila @ 2023-11-25 11:05 UTC (permalink / raw)
  To: Shlok Kyal <shlok.kyal.oss@gmail.com>; +Cc: Tomas Vondra <tomas.vondra@enterprisedb.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On Fri, Nov 24, 2023 at 5:05 PM Shlok Kyal <shlok.kyal.oss@gmail.com> wrote:
>
> > I tried to reproduce the issue and was able to reproduce it with
> > scripts shared by Tomas.
> > I tried testing it from PG17 to PG 11. This issue is reproducible for
> > each version.
> >
> > Next I would try to test with the patch in the thread shared by Amit.
>
> I have created the v1 patch to resolve the issue. Have tested the
> patch on HEAD to PG12.
> The same patch applies to all the versions. The changes are similar to
> the one posted in the thread
> https://www.postgresql.org/message-id/1412708.1674417574%40sss.pgh.pa.us
>

(it's quite likely we hold lock on
+ * pg_replication_origin, which the sync worker will need
+ * to update).

This part of the comment is stale and doesn't hold true. You need to
update the reason based on the latest problem discovered in this
thread. I think you can compare the timing of regression tests in
subscription, with and without the patch to show there is no
regression. And probably some tests with a large number of tables for
sync with very little data.

-- 
With Regards,
Amit Kapila.





^ permalink  raw  reply  [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-12-02 16:22  Shlok Kyal <shlok.kyal.oss@gmail.com>
  parent: Amit Kapila <amit.kapila16@gmail.com>
  0 siblings, 1 reply; 23+ messages in thread

From: Shlok Kyal @ 2023-12-02 16:22 UTC (permalink / raw)
  To: Amit Kapila <amit.kapila16@gmail.com>; +Cc: Tomas Vondra <tomas.vondra@enterprisedb.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

Hi,

> thread. I think you can compare the timing of regression tests in
> subscription, with and without the patch to show there is no
> regression. And probably some tests with a large number of tables for
> sync with very little data.

I have tested the regression test timings for subscription with and
without patch. I also did the timing test for sync of subscription
with the publisher for 100 and 1000 tables respectively.
I have attached the test script and results of the timing test are as follows:

Time taken for test to run in Linux VM
Summary                                |  Subscription Test (sec)
|    100 tables in pub and Sub (sec)    |  1000 tables in pub and Sub
(sec)
Without patch Release           |  95.564
 |     7.877                                             |   58.919
With patch Release                |  96.513
   |     6.533                                             |   45.807

Time Taken for test to run in another Linux VM
Summary                                |  Subscription Test (sec)
|    100 tables in pub and Sub (sec)    |  1000 tables in pub and Sub
(sec)
Without patch Release           |  109.8145
|    6.4675                                           |    83.001
With patch Release                |  113.162
   |    7.947                                              |   87.113

Time Taken for test to run in Performance Machine Linux
Summary                                |  Subscription Test (sec)
|    100 tables in pub and Sub (sec)    |  1000 tables in pub and Sub
(sec)
Without patch Release           |  115.871
 |     6.656                                             |   81.157
With patch Release                |  115.922
   |     6.7305                                           |   81.1525

thoughts?

Thanks and Regards,
Shlok Kyal

Attachments:

  034_tmp.pl (application/octet-stream, 1.4K) download

^ permalink  raw  reply  [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-12-04 11:37  Amit Kapila <amit.kapila16@gmail.com>
  parent: Shlok Kyal <shlok.kyal.oss@gmail.com>
  0 siblings, 1 reply; 23+ messages in thread

From: Amit Kapila @ 2023-12-04 11:37 UTC (permalink / raw)
  To: Shlok Kyal <shlok.kyal.oss@gmail.com>; +Cc: Tomas Vondra <tomas.vondra@enterprisedb.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On Sat, Dec 2, 2023 at 9:52 PM Shlok Kyal <shlok.kyal.oss@gmail.com> wrote:
>
> > thread. I think you can compare the timing of regression tests in
> > subscription, with and without the patch to show there is no
> > regression. And probably some tests with a large number of tables for
> > sync with very little data.
>
> I have tested the regression test timings for subscription with and
> without patch. I also did the timing test for sync of subscription
> with the publisher for 100 and 1000 tables respectively.
> I have attached the test script and results of the timing test are as follows:
>
> Time taken for test to run in Linux VM
> Summary                                |  Subscription Test (sec)
> |    100 tables in pub and Sub (sec)    |  1000 tables in pub and Sub
> (sec)
> Without patch Release           |  95.564
>  |     7.877                                             |   58.919
> With patch Release                |  96.513
>    |     6.533                                             |   45.807
>
> Time Taken for test to run in another Linux VM
> Summary                                |  Subscription Test (sec)
> |    100 tables in pub and Sub (sec)    |  1000 tables in pub and Sub
> (sec)
> Without patch Release           |  109.8145
> |    6.4675                                           |    83.001
> With patch Release                |  113.162
>    |    7.947                                              |   87.113
>

So, on some machines, it may increase the test timing although not too
much. I think the reason is probably doing the work in multiple
transactions for multiple relations. I am wondering that instead of
committing and starting a new transaction before
wait_for_relation_state_change(), what if we do it inside that
function just before we decide to wait? It is quite possible that in
many cases we don't need any wait at all.

-- 
With Regards,
Amit Kapila.





^ permalink  raw  reply  [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-12-04 12:00  Tomas Vondra <tomas.vondra@enterprisedb.com>
  parent: Amit Kapila <amit.kapila16@gmail.com>
  0 siblings, 2 replies; 23+ messages in thread

From: Tomas Vondra @ 2023-12-04 12:00 UTC (permalink / raw)
  To: Amit Kapila <amit.kapila16@gmail.com>; Shlok Kyal <shlok.kyal.oss@gmail.com>; +Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>



On 12/4/23 12:37, Amit Kapila wrote:
> On Sat, Dec 2, 2023 at 9:52 PM Shlok Kyal <shlok.kyal.oss@gmail.com> wrote:
>>
>>> thread. I think you can compare the timing of regression tests in
>>> subscription, with and without the patch to show there is no
>>> regression. And probably some tests with a large number of tables for
>>> sync with very little data.
>>
>> I have tested the regression test timings for subscription with and
>> without patch. I also did the timing test for sync of subscription
>> with the publisher for 100 and 1000 tables respectively.
>> I have attached the test script and results of the timing test are as follows:
>>
>> Time taken for test to run in Linux VM
>> Summary                                |  Subscription Test (sec)
>> |    100 tables in pub and Sub (sec)    |  1000 tables in pub and Sub
>> (sec)
>> Without patch Release           |  95.564
>>  |     7.877                                             |   58.919
>> With patch Release                |  96.513
>>    |     6.533                                             |   45.807
>>
>> Time Taken for test to run in another Linux VM
>> Summary                                |  Subscription Test (sec)
>> |    100 tables in pub and Sub (sec)    |  1000 tables in pub and Sub
>> (sec)
>> Without patch Release           |  109.8145
>> |    6.4675                                           |    83.001
>> With patch Release                |  113.162
>>    |    7.947                                              |   87.113
>>
> 
> So, on some machines, it may increase the test timing although not too
> much. I think the reason is probably doing the work in multiple
> transactions for multiple relations. I am wondering that instead of
> committing and starting a new transaction before
> wait_for_relation_state_change(), what if we do it inside that
> function just before we decide to wait? It is quite possible that in
> many cases we don't need any wait at all.
> 

I'm not sure what you mean by "do it". What should the function do?

As for the test results, I very much doubt the differences are not
caused simply by random timing variations, or something like that. And I
don't understand what "Performance Machine Linux" is, considering those
timings are slower than the other two machines.

Also, even if it was a bit slower, does it really matter? I mean, the
current code is wrong, can lead to infinite duration if it happens to
hit the deadlock. And it's a one-time action, I don't think it's a very
sensitive in terms of performance.

regards

-- 
Tomas Vondra
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company





^ permalink  raw  reply  [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-12-04 12:11  Amit Kapila <amit.kapila16@gmail.com>
  parent: Tomas Vondra <tomas.vondra@enterprisedb.com>
  1 sibling, 1 reply; 23+ messages in thread

From: Amit Kapila @ 2023-12-04 12:11 UTC (permalink / raw)
  To: Tomas Vondra <tomas.vondra@enterprisedb.com>; +Cc: Shlok Kyal <shlok.kyal.oss@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On Mon, Dec 4, 2023 at 5:30 PM Tomas Vondra
<tomas.vondra@enterprisedb.com> wrote:
>
> On 12/4/23 12:37, Amit Kapila wrote:
> > On Sat, Dec 2, 2023 at 9:52 PM Shlok Kyal <shlok.kyal.oss@gmail.com> wrote:
> >>
> >>> thread. I think you can compare the timing of regression tests in
> >>> subscription, with and without the patch to show there is no
> >>> regression. And probably some tests with a large number of tables for
> >>> sync with very little data.
> >>
> >> I have tested the regression test timings for subscription with and
> >> without patch. I also did the timing test for sync of subscription
> >> with the publisher for 100 and 1000 tables respectively.
> >> I have attached the test script and results of the timing test are as follows:
> >>
> >> Time taken for test to run in Linux VM
> >> Summary                                |  Subscription Test (sec)
> >> |    100 tables in pub and Sub (sec)    |  1000 tables in pub and Sub
> >> (sec)
> >> Without patch Release           |  95.564
> >>  |     7.877                                             |   58.919
> >> With patch Release                |  96.513
> >>    |     6.533                                             |   45.807
> >>
> >> Time Taken for test to run in another Linux VM
> >> Summary                                |  Subscription Test (sec)
> >> |    100 tables in pub and Sub (sec)    |  1000 tables in pub and Sub
> >> (sec)
> >> Without patch Release           |  109.8145
> >> |    6.4675                                           |    83.001
> >> With patch Release                |  113.162
> >>    |    7.947                                              |   87.113
> >>
> >
> > So, on some machines, it may increase the test timing although not too
> > much. I think the reason is probably doing the work in multiple
> > transactions for multiple relations. I am wondering that instead of
> > committing and starting a new transaction before
> > wait_for_relation_state_change(), what if we do it inside that
> > function just before we decide to wait? It is quite possible that in
> > many cases we don't need any wait at all.
> >
>
> I'm not sure what you mean by "do it". What should the function do?
>

I mean to commit the open transaction at the below place in
wait_for_relation_state_change()

wait_for_relation_state_change()
{
...
-- commit the xact
WaitLatch();
...
}

Then start after the wait is over. This is just to test whether it
improves the difference in regression test timing.

> As for the test results, I very much doubt the differences are not
> caused simply by random timing variations, or something like that. And I
> don't understand what "Performance Machine Linux" is, considering those
> timings are slower than the other two machines.
>
> Also, even if it was a bit slower, does it really matter? I mean, the
> current code is wrong, can lead to infinite duration if it happens to
> hit the deadlock. And it's a one-time action, I don't think it's a very
> sensitive in terms of performance.
>

Yeah, I see that point but trying to evaluate if we can avoid an
increase in regression test timing at least for the HEAD. The tests
are done in release mode, so, I suspect there could be a slightly
bigger gap in debug mode (we can check that once though) which may hit
developers running regressions quite often in their development
environments. Now, if we there is no easy way to avoid the increase in
regression test timing, we have to still fix the problem, so we have
to take the hit of some increase in time.

-- 
With Regards,
Amit Kapila.





^ permalink  raw  reply  [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-12-05 07:14  Shlok Kyal <shlok.kyal.oss@gmail.com>
  parent: Tomas Vondra <tomas.vondra@enterprisedb.com>
  1 sibling, 1 reply; 23+ messages in thread

From: Shlok Kyal @ 2023-12-05 07:14 UTC (permalink / raw)
  To: Tomas Vondra <tomas.vondra@enterprisedb.com>; +Cc: Amit Kapila <amit.kapila16@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

Hi,

> As for the test results, I very much doubt the differences are not
> caused simply by random timing variations, or something like that. And I
> don't understand what "Performance Machine Linux" is, considering those
> timings are slower than the other two machines.

The machine has Total Memory of 755.536 GB, 120 CPUs and RHEL 7 Operating System
Also find the detailed info of the performance machine attached.

Thanks and Regards,
Shlok Kyal

Attachments:

memory_info.txt (text/plain, 1.0K) download MemTotal: 755.536 GB MemFree: 748.281 GB MemAvailable: 748.581 GB Buffers: 0.002 GB Cached: 1.366 GB SwapCached: 0.000 GB Active: 0.834 GB Inactive: 0.745 GB Active(anon): 0.221 GB Inactive(anon): 0.028 GB Active(file): 0.614 GB Inactive(file): 0.717 GB Unevictable: 0.000 GB Mlocked: 0.000 GB SwapTotal: 4.000 GB SwapFree: 4.000 GB Dirty: 0.000 GB Writeback: 0.000 GB AnonPages: 0.212 GB Mapped: 0.142 GB Shmem: 0.038 GB Slab: 0.468 GB SReclaimable: 0.139 GB SUnreclaim: 0.329 GB KernelStack: 0.020 GB PageTables: 0.023 GB NFS_Unstable: 0.000 GB Bounce: 0.000 GB WritebackTmp: 0.000 GB CommitLimit: 381.768 GB Committed_AS: 0.681 GB VmallocTotal: 32768.000 GB VmallocUsed: 1.852 GB VmallocChunk: 32189.748 GB Percpu: 0.035 GB HardwareCorrupted: 0.000 GB AnonHugePages: 0.025 GB CmaTotal: 0.000 GB CmaFree: 0.000 GB HugePages_Total: 0.000 GB HugePages_Free: 0.000 GB HugePages_Rsvd: 0.000 GB HugePages_Surp: 0.000 GB Hugepagesize: 0.002 GB DirectMap4k: 0.314 GB DirectMap2M: 6.523 GB DirectMap1G: 763.000 GB
cpu_info.txt (text/plain, 1.0K) download processor : 0 vendor_id : GenuineIntel cpu family : 6 model : 62 model name : Intel(R) Xeon(R) CPU E7-4890 v2 @ 2.80GHz stepping : 7 microcode : 0x715 cpu MHz : 1762.646 cache size : 38400 KB physical id : 0 siblings : 30 core id : 0 cpu cores : 15 apicid : 0 initial apicid : 0 fpu : yes fpu_exception : yes cpuid level : 13 wp : yes flags : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc aperfmperf eagerfpu pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid dca sse4_1 sse4_2 x2apic popcnt tsc_deadline_timer aes xsave avx f16c rdrand lahf_lm epb intel_ppin ssbd ibrs ibpb stibp tpr_shadow vnmi flexpriority ept vpid fsgsbase smep erms xsaveopt dtherm ida arat pln pts md_clear spec_ctrl intel_stibp flush_l1d bogomips : 5586.07 clflush size : 64 cache_alignment : 64 address sizes : 46 bits physical, 48 bits virtual power management:
os_info.txt (text/plain, 549B) download NAME="Red Hat Enterprise Linux Server" VERSION="7.8 (Maipo)" ID="rhel" ID_LIKE="fedora" VARIANT="Server" VARIANT_ID="server" VERSION_ID="7.8" PRETTY_NAME="Red Hat Enterprise Linux Server 7.8 (Maipo)" ANSI_COLOR="0;31" CPE_NAME="cpe:/o:redhat:enterprise_linux:7.8:GA:server" HOME_URL="https://www.redhat.com/" BUG_REPORT_URL="https://bugzilla.redhat.com/" REDHAT_BUGZILLA_PRODUCT="Red Hat Enterprise Linux 7" REDHAT_BUGZILLA_PRODUCT_VERSION=7.8 REDHAT_SUPPORT_PRODUCT="Red Hat Enterprise Linux" REDHAT_SUPPORT_PRODUCT_VERSION="7.8"
^ permalink raw reply [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-12-05 11:48  Tomas Vondra <tomas.vondra@enterprisedb.com>
  parent: Shlok Kyal <shlok.kyal.oss@gmail.com>
  0 siblings, 1 reply; 23+ messages in thread

From: Tomas Vondra @ 2023-12-05 11:48 UTC (permalink / raw)
  To: Shlok Kyal <shlok.kyal.oss@gmail.com>; +Cc: Amit Kapila <amit.kapila16@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On 12/5/23 08:14, Shlok Kyal wrote:
> Hi,
> 
>> As for the test results, I very much doubt the differences are not
>> caused simply by random timing variations, or something like that. And I
>> don't understand what "Performance Machine Linux" is, considering those
>> timings are slower than the other two machines.
> 
> The machine has Total Memory of 755.536 GB, 120 CPUs and RHEL 7 Operating System
> Also find the detailed info of the performance machine attached.
> 

Thanks for the info. I don't think the tests really benefit from this
much resources, I would be rather surprised if it was faster beyond 8
cores or so. The CPU frequency likely matters much more. Which probably
explains why this machine was the slowest.

Also, I wonder how much the results vary between the runs. I suppose you
only did s single run for each, right?

regards

-- 
Tomas Vondra
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company





^ permalink  raw  reply  [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-12-06 05:25  Shlok Kyal <shlok.kyal.oss@gmail.com>
  parent: Tomas Vondra <tomas.vondra@enterprisedb.com>
  0 siblings, 0 replies; 23+ messages in thread

From: Shlok Kyal @ 2023-12-06 05:25 UTC (permalink / raw)
  To: Tomas Vondra <tomas.vondra@enterprisedb.com>; +Cc: Amit Kapila <amit.kapila16@gmail.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On Tue, 5 Dec 2023 at 17:18, Tomas Vondra <tomas.vondra@enterprisedb.com> wrote:
>
> On 12/5/23 08:14, Shlok Kyal wrote:
> > Hi,
> >
> >> As for the test results, I very much doubt the differences are not
> >> caused simply by random timing variations, or something like that. And I
> >> don't understand what "Performance Machine Linux" is, considering those
> >> timings are slower than the other two machines.
> >
> > The machine has Total Memory of 755.536 GB, 120 CPUs and RHEL 7 Operating System
> > Also find the detailed info of the performance machine attached.
> >
>
> Thanks for the info. I don't think the tests really benefit from this
> much resources, I would be rather surprised if it was faster beyond 8
> cores or so. The CPU frequency likely matters much more. Which probably
> explains why this machine was the slowest.
>
> Also, I wonder how much the results vary between the runs. I suppose you
> only did s single run for each, right?

I did 10 runs for each of the cases and reported the median result in
the previous thread.
I have documented the result of the runs and have attached the same here.

Thanks and Regards,
Shlok Kyal

Attachments:

  Performance_Test.xlsx (application/vnd.openxmlformats-officedocument.spreadsheetml.sheet, 16.5K) download

^ permalink  raw  reply  [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-12-07 05:51  Shlok Kyal <shlok.kyal.oss@gmail.com>
  parent: Amit Kapila <amit.kapila16@gmail.com>
  0 siblings, 1 reply; 23+ messages in thread

From: Shlok Kyal @ 2023-12-07 05:51 UTC (permalink / raw)
  To: Amit Kapila <amit.kapila16@gmail.com>; +Cc: Tomas Vondra <tomas.vondra@enterprisedb.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

Hi,

> I mean to commit the open transaction at the below place in
> wait_for_relation_state_change()
>
> wait_for_relation_state_change()
> {
> ...
> -- commit the xact
> WaitLatch();
> ...
> }
>
> Then start after the wait is over. This is just to test whether it
> improves the difference in regression test timing.

I tried the above approach and observed that the performance of this
approach is nearly same as the previous approach.

For Linux VM:
Summary    | Subscription | 100 tables in pub  | 1000 tables in pub
                    | Test (sec)     | and Sub (sec)       | and Sub (sec)
------------------------------------------------------------------------------
old patch     |  107.4545     |   6.911           | 77.918
alternate      |  108.3985    | 6.9835           | 78.111
approach

For Performance Machine:
Summary    | Subscription | 100 tables in pub  | 1000 tables in pub
                    | Test (sec)     | and Sub (sec)       | and Sub (sec)
------------------------------------------------------------------------------
old patch     |  115.922      |   6.7305         | 81.1525
alternate      |  115.8215   | 6.7685            | 81.2335
approach

I have attached the patch for this approach as 'alternate_approach.patch'.

Since the performance is the same, I think that the previous approach
is better. As in this approach we are using CommitTransactionCommand()
and StartTransactionCommand() inside a 'for loop'.

I also fixed the comment in previous approach and attached here as
'v2-0001-Deadlock-when-apply-worker-tablesync-worker-and-c.patch'

Thanks and Regards


Shlok Kyal

Attachments: download all (2 files, .tar.gz)

v2-0001-Deadlock-when-apply-worker-tablesync-worker-and-c.patch (application/x-patch, 2.5K) download From 11072d138d900227b963b54d1a3626cf256db721 Mon Sep 17 00:00:00 2001 From: Shlok Kyal <shlok.kyal.oss@gmail.com> Date: Fri, 24 Nov 2023 16:37:14 +0530 Subject: [PATCH v2] Deadlock when apply worker,tablesync worker and client backend run parallelly. Apply worker holds a lock on the table pg_subscription_rel and waits for notification from the tablesync workers where the relation is synced, which happens through updating the pg_subscription_rel row. And that wait happens in wait_for_relation_state_change, which simply checks the row in a loop, with a sleep by WaitLatch(). Unfortunately, the tablesync workers can't update the row because the client backend executing ALTER SUBSCRIPTION ... REFRESH PUBLICATION sneaked in, and waits for an AccessExclusiveLock. So the tablesync workers are stuck in the queue and can't proceed. The client backend is waiting for a lock held by the apply worker. The tablesync workers can't proceed because their lock request is stuck behind the AccessExclusiveLock request. And the apply worker is waiting for status update from the tablesync workers. And the deadlock is undetected, because the apply worker is not waiting on a lock, but sleeping on a latch. We have resolved the issue by releasing the lock by commiting the transaction before the apply worker goes to wait state. --- src/backend/replication/logical/tablesync.c | 17 ++++++++++++++--- 1 file changed, 14 insertions(+), 3 deletions(-) diff --git a/src/backend/replication/logical/tablesync.c b/src/backend/replication/logical/tablesync.c index df3c42eb5d..b71234d998 100644 --- a/src/backend/replication/logical/tablesync.c +++ b/src/backend/replication/logical/tablesync.c @@ -542,15 +542,26 @@ process_syncing_tables_for_apply(XLogRecPtr current_lsn) LWLockRelease(LogicalRepWorkerLock); /* - * Enter busy loop and wait for synchronization worker to - * reach expected state (or die trying). + * If we have a transaction, we must commit it to release + * any locks we have. Then start a new transaction so we + * can examine catalog state. */ - if (!started_tx) + if (started_tx) + { + CommitTransactionCommand(); + pgstat_report_stat(false); + StartTransactionCommand(); + } + else { StartTransactionCommand(); started_tx = true; } + /* + * Enter busy loop and wait for synchronization worker to + * reach expected state (or die trying). + */ wait_for_relation_state_change(rstate->relid, SUBREL_STATE_SYNCDONE); } -- 2.34.1
alternate-approach.patch (application/x-patch, 2.7K) download From ce261399d22a7fd9ee7ccdd3b9d1cc7f4f72ce4b Mon Sep 17 00:00:00 2001 From: Shlok Kyal <shlok.kyal.oss@gmail.com> Date: Thu, 7 Dec 2023 10:55:26 +0530 Subject: [PATCH] Deadlock when apply worker,tablesync worker and client backend run parallelly. Apply worker holds a lock on the table pg_subscription_rel and waits for notification from the tablesync workers where the relation is synced, which happens through updating the pg_subscription_rel row. And that wait happens in wait_for_relation_state_change, which simply checks the row in a loop, with a sleep by WaitLatch(). Unfortunately, the tablesync workers can't update the row because the client backend executing ALTER SUBSCRIPTION ... REFRESH PUBLICATION sneaked in, and waits for an AccessExclusiveLock. So the tablesync workers are stuck in the queue and can't proceed. The client backend is waiting for a lock held by the apply worker. The tablesync workers can't proceed because their lock request is stuck behind the AccessExclusiveLock request. And the apply worker is waiting for status update from the tablesync workers. And the deadlock is undetected, because the apply worker is not waiting on a lock, but sleeping on a latch. We have resolved the issue by releasing the lock by commiting the transaction before the apply worker goes to wait state. --- src/backend/replication/logical/tablesync.c | 15 +++++++++++++-- 1 file changed, 13 insertions(+), 2 deletions(-) diff --git a/src/backend/replication/logical/tablesync.c b/src/backend/replication/logical/tablesync.c index df3c42eb5d..fb0ac84450 100644 --- a/src/backend/replication/logical/tablesync.c +++ b/src/backend/replication/logical/tablesync.c @@ -174,7 +174,7 @@ finish_sync_worker(void) * CATCHUP state to SYNCDONE. */ static bool -wait_for_relation_state_change(Oid relid, char expected_state) +wait_for_relation_state_change(Oid relid, char expected_state, bool *started_tx) { char state; @@ -203,6 +203,16 @@ wait_for_relation_state_change(Oid relid, char expected_state) if (!worker) break; + /* + * If we have a transaction, we must commit it to release any locks we + * have. Then start a new transaction so we can examine catalog state. + */ + if (*started_tx) + { + CommitTransactionCommand(); + pgstat_report_stat(false); + StartTransactionCommand(); + } (void) WaitLatch(MyLatch, WL_LATCH_SET | WL_TIMEOUT | WL_EXIT_ON_PM_DEATH, 1000L, WAIT_EVENT_LOGICAL_SYNC_STATE_CHANGE); @@ -552,7 +562,8 @@ process_syncing_tables_for_apply(XLogRecPtr current_lsn) } wait_for_relation_state_change(rstate->relid, - SUBREL_STATE_SYNCDONE); + SUBREL_STATE_SYNCDONE, + &started_tx); } else LWLockRelease(LogicalRepWorkerLock); -- 2.34.1
^ permalink raw reply [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-12-08 11:45  Amit Kapila <amit.kapila16@gmail.com>
  parent: Shlok Kyal <shlok.kyal.oss@gmail.com>
  0 siblings, 1 reply; 23+ messages in thread

From: Amit Kapila @ 2023-12-08 11:45 UTC (permalink / raw)
  To: Shlok Kyal <shlok.kyal.oss@gmail.com>; +Cc: Tomas Vondra <tomas.vondra@enterprisedb.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On Thu, Dec 7, 2023 at 11:21 AM Shlok Kyal <shlok.kyal.oss@gmail.com> wrote:
>
> > I mean to commit the open transaction at the below place in
> > wait_for_relation_state_change()
> >
> > wait_for_relation_state_change()
> > {
> > ...
> > -- commit the xact
> > WaitLatch();
> > ...
> > }
> >
> > Then start after the wait is over. This is just to test whether it
> > improves the difference in regression test timing.
>
> I tried the above approach and observed that the performance of this
> approach is nearly same as the previous approach.
>

Then let's go with the original patch only. BTW, it took almost the
same time (105 wallclock secs) in my environment (CentOs VM) to run
tests in src/test/subscription both with and without the patch. I took
a median of five runs. I have slightly adjusted the comments and
commit message in the attached. If you are fine with this, we can
commit and backpatch this.

-- 
With Regards,
Amit Kapila.

Attachments:

v3-0001-Fix-an-undetected-deadlock-due-to-apply-worker.patch (application/octet-stream, 2.9K) download From d9d97f1179f46b1c3763ed9339d8c75019583d55 Mon Sep 17 00:00:00 2001 From: Amit Kapila <akapila@postgresql.org> Date: Fri, 8 Dec 2023 17:07:51 +0530 Subject: [PATCH v3] Fix an undetected deadlock due to apply worker. The apply worker needs to update the state of the subscription tables to 'READY' during the synchronization phase which requires locking the corresponding subscription. The apply worker also waits for the subscription tables to reach the 'SYNCDONE' state after holding the locks on the subscription and the wait is done using WaitLatch. The 'SYNCDONE' state is changed by tablesync workers again by locking the corresponding subscription. Both the state updates use AccessShareLock mode to lock the subscription, so they can't block each other. However, a backend can simultaneously try to acquire a lock on the same subscription using AccessExclusiveLock mode to alter the subscription. Now, the backend's wait on a lock can sneak in between the apply worker and table sync worker causing deadlock. In other words, apply_worker waits for tablesync worker which waits for backend, and backend waits for apply worker. This is not detected by the deadlock detector because apply worker uses WaitLatch. The fix is to release existing locks in apply worker before it starts to wait for tablesync worker to change the state. Reported-by: Tomas Vondra Author: Shlok Kyal Reviewed-by: Amit Kapila Backpatch-through: 12 Discussion: https://postgr.es/m/d291bb50-12c4-e8af-2af2-7bb9bb4d8e3e@enterprisedb.com --- src/backend/replication/logical/tablesync.c | 23 ++++++++++++++++----- 1 file changed, 18 insertions(+), 5 deletions(-) diff --git a/src/backend/replication/logical/tablesync.c b/src/backend/replication/logical/tablesync.c index df3c42eb5d..2bdc1bab55 100644 --- a/src/backend/replication/logical/tablesync.c +++ b/src/backend/replication/logical/tablesync.c @@ -541,16 +541,29 @@ process_syncing_tables_for_apply(XLogRecPtr current_lsn) /* Now safe to release the LWLock */ LWLockRelease(LogicalRepWorkerLock); - /* - * Enter busy loop and wait for synchronization worker to - * reach expected state (or die trying). - */ - if (!started_tx) + if (started_tx) + { + /* + * We must commit the existing transaction to release + * the existing locks before entering a busy loop. This + * is required to avoid any undetected deadlocks due to + * any existing lock as deadlock detector won't be able + * to detect the waits on the latch. + */ + CommitTransactionCommand(); + pgstat_report_stat(false); + StartTransactionCommand(); + } + else { StartTransactionCommand(); started_tx = true; } + /* + * Enter busy loop and wait for synchronization worker to + * reach expected state (or die trying). + */ wait_for_relation_state_change(rstate->relid, SUBREL_STATE_SYNCDONE); } -- 2.28.0.windows.1
^ permalink raw reply [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-12-08 13:46  Shlok Kyal <shlok.kyal.oss@gmail.com>
  parent: Amit Kapila <amit.kapila16@gmail.com>
  0 siblings, 1 reply; 23+ messages in thread

From: Shlok Kyal @ 2023-12-08 13:46 UTC (permalink / raw)
  To: Amit Kapila <amit.kapila16@gmail.com>; +Cc: Tomas Vondra <tomas.vondra@enterprisedb.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

Hi,

> Then let's go with the original patch only. BTW, it took almost the
> same time (105 wallclock secs) in my environment (CentOs VM) to run
> tests in src/test/subscription both with and without the patch. I took
> a median of five runs. I have slightly adjusted the comments and
> commit message in the attached. If you are fine with this, we can
> commit and backpatch this.

I have tested the patch for all the branches from PG 17 to PG 12.
The same patch applies cleanly on all branches. Also, the same patch
resolves the issue on all the branches.
I ran all the tests and all the tests passed on each branch.

I also reviewed the patch and it looks good to me.

Thanks and Regards,
Shlok Kyal





^ permalink  raw  reply  [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-12-09 06:46  Amit Kapila <amit.kapila16@gmail.com>
  parent: Shlok Kyal <shlok.kyal.oss@gmail.com>
  0 siblings, 1 reply; 23+ messages in thread

From: Amit Kapila @ 2023-12-09 06:46 UTC (permalink / raw)
  To: Shlok Kyal <shlok.kyal.oss@gmail.com>; +Cc: Tomas Vondra <tomas.vondra@enterprisedb.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On Fri, Dec 8, 2023 at 7:16 PM Shlok Kyal <shlok.kyal.oss@gmail.com> wrote:
>
> > Then let's go with the original patch only. BTW, it took almost the
> > same time (105 wallclock secs) in my environment (CentOs VM) to run
> > tests in src/test/subscription both with and without the patch. I took
> > a median of five runs. I have slightly adjusted the comments and
> > commit message in the attached. If you are fine with this, we can
> > commit and backpatch this.
>
> I have tested the patch for all the branches from PG 17 to PG 12.
> The same patch applies cleanly on all branches. Also, the same patch
> resolves the issue on all the branches.
> I ran all the tests and all the tests passed on each branch.
>
> I also reviewed the patch and it looks good to me.
>

Thanks, I could also reproduce the issue on back branches (tried till
12), and the fix works. I'll push this on Monday.

-- 
With Regards,
Amit Kapila.





^ permalink  raw  reply  [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-12-11 06:12  Amit Kapila <amit.kapila16@gmail.com>
  parent: Amit Kapila <amit.kapila16@gmail.com>
  0 siblings, 1 reply; 23+ messages in thread

From: Amit Kapila @ 2023-12-11 06:12 UTC (permalink / raw)
  To: Shlok Kyal <shlok.kyal.oss@gmail.com>; Peter Smith <smithpb2250@gmail.com>; +Cc: Tomas Vondra <tomas.vondra@enterprisedb.com>; PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On Sat, Dec 9, 2023 at 12:16 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
>
> Thanks, I could also reproduce the issue on back branches (tried till
> 12), and the fix works. I'll push this on Monday.
>

Peter sent one minor suggestion (to write the check differently for
easier understanding) offlist which I addressed and pushed the patch.

-- 
With Regards,
Amit Kapila.





^ permalink  raw  reply  [nested|flat] 23+ messages in thread

* Re: undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION
@ 2023-12-11 15:36  Tomas Vondra <tomas.vondra@enterprisedb.com>
  parent: Amit Kapila <amit.kapila16@gmail.com>
  0 siblings, 0 replies; 23+ messages in thread

From: Tomas Vondra @ 2023-12-11 15:36 UTC (permalink / raw)
  To: Amit Kapila <amit.kapila16@gmail.com>; Shlok Kyal <shlok.kyal.oss@gmail.com>; Peter Smith <smithpb2250@gmail.com>; +Cc: PostgreSQL Hackers <pgsql-hackers@lists.postgresql.org>

On 12/11/23 07:12, Amit Kapila wrote:
> On Sat, Dec 9, 2023 at 12:16 PM Amit Kapila <amit.kapila16@gmail.com> wrote:
>>
>> Thanks, I could also reproduce the issue on back branches (tried till
>> 12), and the fix works. I'll push this on Monday.
>>
> 
> Peter sent one minor suggestion (to write the check differently for
> easier understanding) offlist which I addressed and pushed the patch.
> 

Thanks for taking care of fixing this!


regards

-- 
Tomas Vondra
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company





^ permalink  raw  reply  [nested|flat] 23+ messages in thread


end of thread, other threads:[~2023-12-11 15:36 UTC | newest]

Thread overview: 23+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2023-11-21 11:47 undetected deadlock in ALTER SUBSCRIPTION ... REFRESH PUBLICATION Tomas Vondra <tomas.vondra@enterprisedb.com>
2023-11-21 13:16 ` Amit Kapila <amit.kapila16@gmail.com>
2023-11-21 13:26   ` Tomas Vondra <tomas.vondra@enterprisedb.com>
2023-11-22 10:38     ` Amit Kapila <amit.kapila16@gmail.com>
2023-11-22 11:21       ` Tomas Vondra <tomas.vondra@enterprisedb.com>
2023-11-23 09:24         ` Amit Kapila <amit.kapila16@gmail.com>
2023-11-23 16:45           ` Tomas Vondra <tomas.vondra@enterprisedb.com>
2023-11-24 04:15             ` Shlok Kyal <shlok.kyal.oss@gmail.com>
2023-11-24 11:35               ` Shlok Kyal <shlok.kyal.oss@gmail.com>
2023-11-25 11:05                 ` Amit Kapila <amit.kapila16@gmail.com>
2023-12-02 16:22                   ` Shlok Kyal <shlok.kyal.oss@gmail.com>
2023-12-04 11:37                     ` Amit Kapila <amit.kapila16@gmail.com>
2023-12-04 12:00                       ` Tomas Vondra <tomas.vondra@enterprisedb.com>
2023-12-04 12:11                         ` Amit Kapila <amit.kapila16@gmail.com>
2023-12-07 05:51                           ` Shlok Kyal <shlok.kyal.oss@gmail.com>
2023-12-08 11:45                             ` Amit Kapila <amit.kapila16@gmail.com>
2023-12-08 13:46                               ` Shlok Kyal <shlok.kyal.oss@gmail.com>
2023-12-09 06:46                                 ` Amit Kapila <amit.kapila16@gmail.com>
2023-12-11 06:12                                   ` Amit Kapila <amit.kapila16@gmail.com>
2023-12-11 15:36                                     ` Tomas Vondra <tomas.vondra@enterprisedb.com>
2023-12-05 07:14                         ` Shlok Kyal <shlok.kyal.oss@gmail.com>
2023-12-05 11:48                           ` Tomas Vondra <tomas.vondra@enterprisedb.com>
2023-12-06 05:25                             ` Shlok Kyal <shlok.kyal.oss@gmail.com>

This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox