Subject: Re: Perform streaming logical transactions by background workers and parallel apply

From: Amit Kapila <[email-masked]>
Date: Wed, 4 Jan 2023 18:40:41 +0530

On Wed, Jan 4, 2023 at 4:52 PM Dilip Kumar <[email-masked]> wrote:
>
> 2.
> + * Since the database structure (schema of subscription tables, constraints,
> + * etc.) of the publisher and subscriber could be different, applying
> + * transactions in parallel mode on the subscriber side can cause some
> + * deadlocks that do not occur on the publisher side.
>
> I think this paragraph needs to be rephrased a bit.  It is saying that
> some deadlock can occur on subscribers which did not occur on the
> publisher.  I think what it should be conveying is that the deadlock
> can occur due to concurrently applying the conflicting/dependent
> transactions which are not conflicting/dependent on the publisher due
> to <explain reason>.  Because if we create the same schema on the
> publisher it might not have ended up in a deadlock instead it would
> have been executed in sequence (due to lock waiting). So the main
> point we are conveying is that the transaction which was independent
> of each other on the publisher could be dependent on the subscriber
> and they can end up in deadlock due to parallel apply.
>

How about changing it to: "We have a risk of deadlock due to
parallelly applying the transactions that were independent on the
publisher side but became dependent on the subscriber side due to the
different database structures (like schema of subscription tables,
constraints, etc.) on each side.

-- 
With Regards,
Amit Kapila.

---

From: Dilip Kumar <[email-masked]>
Date: Wed, 4 Jan 2023 18:59:24 +0530

> constraints, etc.) on each side.

I think this looks good to me.

-- 
Regards,
Dilip Kumar
EnterpriseDB: http://www.enterprisedb.com

---

From: "[email-masked]" <[email-masked]>
Date: Thu, 5 Jan 2023 03:37:46 +0000

On Wednesday, January 4, 2023 9:29 PM Dilip Kumar <[email-masked]> wrote:
> > > + * Since the database structure (schema of subscription tables,
> > > + constraints,
> > > + * etc.) of the publisher and subscriber could be different,
> > > + applying
> > > + * transactions in parallel mode on the subscriber side can cause
> > > + some
> > > I think this paragraph needs to be rephrased a bit.  It is saying
> > > that some deadlock can occur on subscribers which did not occur on
> > > the publisher.  I think what it should be conveying is that the
> > > deadlock can occur due to concurrently applying the
> > > conflicting/dependent transactions which are not
> > > conflicting/dependent on the publisher due to <explain reason>.
> > > Because if we create the same schema on the publisher it might not
> > > have ended up in a deadlock instead it would have been executed in
> > > sequence (due to lock waiting). So the main point we are conveying
> > > is that the transaction which was independent of each other on the
> > > publisher could be dependent on the subscriber and they can end up in
> deadlock due to parallel apply.
> > >
> >

Thanks for the comments.
Attach the new version patch set which changed the comments as suggested.

Best regards,
Hou zj

---

From: Dilip Kumar <[email-masked]>
Date: Thu, 5 Jan 2023 13:51:53 +0530

> Attach the new version patch set which changed the comments as suggested.

Thanks for the updated patch, while testing this I see one strange
behavior which seems like bug to me, here is the step to reproduce

1. start 2 servers(config: logical_decoding_work_mem=64kB)
./pg_ctl -D data/ -c -l pub_logs start
./pg_ctl -D data1/ -c -l sub_logs start

2. Publisher:
create table t(a int PRIMARY KEY ,b text);
CREATE OR REPLACE FUNCTION large_val() RETURNS TEXT LANGUAGE SQL AS
'select array_agg(md5(g::text))::text from generate_series(1, 256) g';
create publication test_pub for table t
with(PUBLISH='insert,delete,update,truncate');
alter table t replica identity FULL ;
insert into t values (generate_series(1,2000),large_val()) ON CONFLICT
(a) DO UPDATE SET a=EXCLUDED.a*300;

3. Subscription Server:
create table t(a int,b text);
create subscription test_sub CONNECTION 'host=localhost port=5432
dbname=postgres' PUBLICATION test_pub WITH ( slot_name =
test_slot_sub1,streaming=parallel);

4. Publication Server:
begin ;
savepoint a;
delete from t;
savepoint b;
insert into t values (generate_series(1,5000),large_val()) ON CONFLICT
(a) DO UPDATE SET a=EXCLUDED.a*30000;  -- (while executing this start
publisher in 2-3 secs)

Restart the publication server, while the transaction is still in an
uncommitted state.
./pg_ctl -D data/ -c -l pub_logs stop -mi
./pg_ctl -D data/ -c -l pub_logs start -mi

after this, the parallel apply worker stuck in waiting on stream lock
forever (even after 10 mins) -- see below, from subscriber logs I can
see one of the parallel apply worker [75677] started but never
finished [no error], after that I have performed more operation [same
insert] which got applied by new parallel apply worked which got
started and finished within 1 second.

dilipku+  75660      1  0 13:39 ?        00:00:00
/home/dilipkumar/work/PG/install/bin/postgres -D data
dilipku+  75661  75660  0 13:39 ?        00:00:00 postgres: checkpointer
dilipku+  75662  75660  0 13:39 ?        00:00:00 postgres: background writer
dilipku+  75664  75660  0 13:39 ?        00:00:00 postgres: walwriter
dilipku+  75665  75660  0 13:39 ?        00:00:00 postgres: autovacuum launcher
dilipku+  75666  75660  0 13:39 ?        00:00:00 postgres: logical
replication launcher
dilipku+  75675  75595  0 13:39 ?        00:00:00 postgres: logical
replication apply worker for subscription 16389
dilipku+  75676  75660  0 13:39 ?        00:00:00 postgres: walsender
dilipkumar postgres ::1(42192) START_REPLICATION
dilipku+  75677  75595  0 13:39 ?        00:00:00 postgres: logical
replication parallel apply worker for subscription 16389  waiting

Subscriber logs:
2023-01-05 13:39:07.261 IST [75595] LOG:  background worker "logical
replication worker" (PID 75649) exited with exit code 1
2023-01-05 13:39:12.272 IST [75675] LOG:  logical replication apply
worker for subscription "test_sub" has started
2023-01-05 13:39:12.307 IST [75677] LOG:  logical replication parallel
apply worker for subscription "test_sub" has started
2023-01-05 13:43:31.003 IST [75596] LOG:  checkpoint starting: time
2023-01-05 13:46:32.045 IST [76337] LOG:  logical replication parallel
apply worker for subscription "test_sub" has started
2023-01-05 13:46:35.214 IST [76337] LOG:  logical replication parallel
apply worker for subscription "test_sub" has finished
2023-01-05 13:46:50.241 IST [76384] LOG:  logical replication parallel
apply worker for subscription "test_sub" has started
2023-01-05 13:46:53.676 IST [76384] LOG:  logical replication parallel
apply worker for subscription "test_sub" has finished

---

From: "[email-masked]" <[email-masked]>
Date: Thu, 5 Jan 2023 11:33:08 +0000

> started and finished within 1 second.

Thanks for reporting the problem.

After analyzing the behavior, I think it's a bug on publisher side which
is not directly related to parallel apply.

I think the root reason is that we didn't try to send a stream end(stream
abort) message to subscriber for the crashed transaction which was streamed
before.

The behavior is that, after restarting, the publisher will start to decode the
transaction that aborted due to crash, and when try to stream the first change
of that transaction, it will send a stream start message but then it realizes
that the transaction was aborted, so it will enter the PG_CATCH block of
ReorderBufferProcessTXN() and call ReorderBufferResetTXN() which send the
stream stop message. And in this case, there would be a parallel apply worker
started on subscriber waiting for stream end message which will never come.

I think the same behavior happens for the non-parallel mode which will cause
a stream file left on subscriber and will not be cleaned until the apply worker is
restarted.

To fix it, I think we need to send a stream abort message when we are cleaning
up crashed transaction on publisher(e.g., in ReorderBufferAbortOld()). And here
is a tiny patch which change the same. I have confirmed that the bug is fixed
and all regression tests pass.

What do you think ?
I will start a new thread and try to write a testcase if possible
after reaching a consensus.

Best regards,
Hou zj

---

From: Dilip Kumar <[email-masked]>
Date: Thu, 5 Jan 2023 17:23:36 +0530

> started on subscriber waiting for stream end message which will never come.

I suspected it but didn't analyze this.

> after reaching a consensus.

I think your analysis looks correct and we can raise this in a new thread.