Re: Bug in logical decoding of in-progress transactions - Mailing list pgsql-hackers
| From | Dilip Kumar |
|---|---|
| Subject | Re: Bug in logical decoding of in-progress transactions |
| Date | |
| Msg-id | CAFiTN-v=e=KovUBCUhDRfODy5juKVNat2LTx69pXYF385a-38Q@mail.gmail.com Whole thread Raw |
| In response to | Bug in logical decoding of in-progress transactions (Amit Kapila <amit.kapila16@gmail.com>) |
| Responses |
Re: Bug in logical decoding of in-progress transactions
|
| List | pgsql-hackers |
On Thu, Sep 10, 2020 at 11:29 AM Amit Kapila <amit.kapila16@gmail.com> wrote:
Hi,
There is a recent build farm failure [1] in one of the test_decoding
tests as pointed by Tom Lane [2]. The failure report is shown below:
@@ -71,6 +71,8 @@
data
------------------------------------------
opening a streamed block for transaction
+ closing a streamed block for transaction
+ opening a streamed block for transaction
streaming change for transaction
streaming change for transaction
streaming change for transaction
@@ -83,7 +85,7 @@
streaming change for transaction
closing a streamed block for transaction
committing streamed transaction
-(13 rows)
+(15 rows)
Here, the symptoms are quite similar to what we have fixed in commit
82a0ba7707 which is that an extra empty transaction is being decoded
in the test. It can happen even if have instructed the test to 'skip
empty xacts' for streaming transactions because the test_decoding
plugin APIs (related to streaming changes for in-progress xacts) makes
no effort to skip such empty xacts. It was kept intentionally like
that under the assumption that we would never try to stream empty
xacts but on closer inspection of the code, it seems to me that
assumption was not correct. Basically, we can pick to stream a
transaction that has change messages for
REORDER_BUFFER_CHANGE_INTERNAL_SNAPSHOT and we don't send such
messages to downstream rather they are just to update the internal
state. So, in this particular failure, it is possible that autovacuum
transaction has got such a change message added by one of the other
committed xact and on trying to stream it we get such additional
messages. The fix is to skip empty xacts when indicated by the user in
streaming APIs of test_decoding.
Thoughts?
Yeah, that's an issue.
[1] - https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=skink&dt=2020-09-09+03%3A42%3A19
[2] - https://www.postgresql.org/message-id/118303.1599691636%40sss.pgh.pa.us
I have written a test case to reproduce the same. I have also prepared a patch to skip the empty transaction. And after that, the issue has been fixed. But the extra side effect will be that it would skip any empty stream even if the transaction is not empty. As such I don't see any problem with that but this is not what the user has asked for.
logical_decoding_work_mem=64kB
SET synchronous_commit = on;
SELECT 'init' FROM pg_create_logical_replication_slot('regression_slot', 'test_decoding');
CREATE TABLE stream_test(data text);
-- consume DDL
SELECT data FROM pg_logical_slot_get_changes('regression_slot', NULL, NULL, 'include-xids', '0', 'skip-empty-xacts', '1');
CREATE OR REPLACE FUNCTION large_val() RETURNS TEXT LANGUAGE SQL AS 'select array_agg(md5(g::text))::text from generate_series(1, 80000) g';
--session1
BEGIN;
CREATE TABLE stream_test1(data text);
--session2
BEGIN;
CREATE TABLE stream_test2(data text);
COMMIT;
--session3
BEGIN;
INSERT INTO stream_test SELECT large_val();
SELECT data FROM pg_logical_slot_get_changes('regression_slot', NULL,NULL, 'include-xids', '1', 'skip-empty-xacts', '1', 'stream-changes', '1');
data
--------------------------------------------------
opening a streamed block for transaction TXN 508
closing a streamed block for transaction TXN 508
opening a streamed block for transaction TXN 510
streaming change for TXN 510
closing a streamed block for transaction TXN 510
(5 rows)
After patch
data
--------------------------------------------------
opening a streamed block for transaction TXN 510
streaming change for TXN 510
closing a streamed block for transaction TXN 510
SELECT 'init' FROM pg_create_logical_replication_slot('regression_slot', 'test_decoding');
CREATE TABLE stream_test(data text);
-- consume DDL
SELECT data FROM pg_logical_slot_get_changes('regression_slot', NULL, NULL, 'include-xids', '0', 'skip-empty-xacts', '1');
CREATE OR REPLACE FUNCTION large_val() RETURNS TEXT LANGUAGE SQL AS 'select array_agg(md5(g::text))::text from generate_series(1, 80000) g';
--session1
BEGIN;
CREATE TABLE stream_test1(data text);
--session2
BEGIN;
CREATE TABLE stream_test2(data text);
COMMIT;
--session3
BEGIN;
INSERT INTO stream_test SELECT large_val();
SELECT data FROM pg_logical_slot_get_changes('regression_slot', NULL,NULL, 'include-xids', '1', 'skip-empty-xacts', '1', 'stream-changes', '1');
data
--------------------------------------------------
opening a streamed block for transaction TXN 508
closing a streamed block for transaction TXN 508
opening a streamed block for transaction TXN 510
streaming change for TXN 510
closing a streamed block for transaction TXN 510
(5 rows)
After patch
data
--------------------------------------------------
opening a streamed block for transaction TXN 510
streaming change for TXN 510
closing a streamed block for transaction TXN 510
Attachment
pgsql-hackers by date: