UPDATE operation terminates logical replication receiver process due to an assertion

Started by Nonamealmost 3 years ago6 messages
#1Noname
v.davydov@postgrespro.ru

Dear all,

I think I've found a problem in logical replication that was introduced
recently in the patch:

Fix calculation of which GENERATED columns need to be updated
https://git.postgresql.org/gitweb/?p=postgresql.git;a=commit;h=3f7836ff651ad710fef52fa87b248ecdfc6468dc

There is an assertion which accidentally terminates logical replication
worker process. The assertion was introduced in the patch. To reproduce
the problem Postgres should be compiled with enabled assertions. The
problem appears when executing UPDATE operation on a non-empty table
with GENERATED columns and a BEFORE UPDATE trigger. The problem seems to
appear on the latest snapshots of 13 and 14 versions (sorry, I haven't
tested other versions).

Stack:
------
TRAP: FailedAssertion("relinfo->ri_GeneratedExprs != NULL", File:
"execUtils.c", Line: 1292)
postgres: logical replication worker for subscription 16401
(ExceptionalCondition+0x89)[0x55838760b902]
postgres: logical replication worker for subscription 16401
(ExecGetExtraUpdatedCols+0x90)[0x558387314bd8]
postgres: logical replication worker for subscription 16401
(ExecGetAllUpdatedCols+0x1c)[0x558387314c20]
postgres: logical replication worker for subscription 16401
(ExecUpdateLockMode+0x19)[0x558387306ce3]
postgres: logical replication worker for subscription 16401
(ExecBRUpdateTriggers+0xc7)[0x5583872debe8]
postgres: logical replication worker for subscription 16401
(ExecSimpleRelationUpdate+0x122)[0x55838730dca7]
postgres: logical replication worker for subscription 16401
(+0x43d32f)[0x55838745632f]
postgres: logical replication worker for subscription 16401
(+0x43e382)[0x558387457382]
postgres: logical replication worker for subscription 16401
(+0x43e5d3)[0x5583874575d3]
postgres: logical replication worker for subscription 16401
(+0x43e76b)[0x55838745776b]
postgres: logical replication worker for subscription 16401
(ApplyWorkerMain+0x3ac)[0x558387457e8b]
postgres: logical replication worker for subscription 16401
(StartBackgroundWorker+0x253)[0x5583874157ed]
postgres: logical replication worker for subscription 16401
(+0x40e9c9)[0x5583874279c9]
postgres: logical replication worker for subscription 16401
(+0x40eb43)[0x558387427b43]
postgres: logical replication worker for subscription 16401
(+0x40fd28)[0x558387428d28]
/lib/x86_64-linux-gnu/libc.so.6(+0x42520)[0x7f08cd44b520]
/lib/x86_64-linux-gnu/libc.so.6(__select+0xbd)[0x7f08cd52474d]
postgres: logical replication worker for subscription 16401
(+0x410ceb)[0x558387429ceb]
postgres: logical replication worker for subscription 16401
(PostmasterMain+0xbf3)[0x55838742ac4d]
postgres: logical replication worker for subscription 16401
(main+0x20c)[0x55838736076d]
/lib/x86_64-linux-gnu/libc.so.6(+0x29d90)[0x7f08cd432d90]
/lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0x80)[0x7f08cd432e40]

How to reproduce:
-----------------
1. Create master-replica configuration with enabled logical replication.
The initial schema is shown below:

CREATE TABLE gtest26 (
a int PRIMARY KEY,
b int GENERATED ALWAYS AS (a * 2) STORED
);

CREATE FUNCTION gtest_trigger_func() RETURNS trigger
LANGUAGE plpgsql
AS $$
BEGIN
IF tg_op IN ('DELETE', 'UPDATE') THEN
RAISE INFO '%: %: old = %', TG_NAME, TG_WHEN, OLD;
END IF;
IF tg_op IN ('INSERT', 'UPDATE') THEN
RAISE INFO '%: %: new = %', TG_NAME, TG_WHEN, NEW;
END IF;
IF tg_op = 'DELETE' THEN
RETURN OLD;
ELSE
RETURN NEW;
END IF;
END
$$;

CREATE TRIGGER gtest1 BEFORE DELETE OR UPDATE ON gtest26
FOR EACH ROW
WHEN (OLD.b < 0) -- ok
EXECUTE PROCEDURE gtest_trigger_func();

INSERT INTO gtest26(a) values (-2), (0), (3)

2. The problem appears if to execute the following sql on the master
node:

UPDATE gtest26 SET a = a + 1;

I'm not sure that this assertion is the proper one and how to properly
fix the issue. That's why I'm asking for some help of the community.
Thank you in advance.

With best regards,
Vitaly

#2Justin Pryzby
pryzby@telsasoft.com
In reply to: Noname (#1)
Re: UPDATE operation terminates logical replication receiver process due to an assertion

On Thu, Jan 12, 2023 at 01:23:57PM +0300, v.davydov@postgrespro.ru wrote:

Dear all,

I think I've found a problem in logical replication that was introduced
recently in the patch:

Fix calculation of which GENERATED columns need to be updated
https://git.postgresql.org/gitweb/?p=postgresql.git;a=commit;h=3f7836ff651ad710fef52fa87b248ecdfc6468dc

There is an assertion which accidentally terminates logical replication
worker process. The assertion was introduced in the patch. To reproduce the
problem Postgres should be compiled with enabled assertions. The problem
appears when executing UPDATE operation on a non-empty table with GENERATED
columns and a BEFORE UPDATE trigger. The problem seems to appear on the
latest snapshots of 13 and 14 versions (sorry, I haven't tested other
versions).

Stack:
------
TRAP: FailedAssertion("relinfo->ri_GeneratedExprs != NULL", File: "execUtils.c", Line: 1292)

Yeah, confirmed under master branch and v15.

Tom ?

--
Justin

#3Tom Lane
tgl@sss.pgh.pa.us
In reply to: Justin Pryzby (#2)
Re: UPDATE operation terminates logical replication receiver process due to an assertion

Justin Pryzby <pryzby@telsasoft.com> writes:

Yeah, confirmed under master branch and v15.
Tom ?

Yeah, sorry, I've been absorbed in $other_stuff. Will look
at this soon. My guess is that this logrep code path is
missing the necessary setup operation.

regards, tom lane

#4Tom Lane
tgl@sss.pgh.pa.us
In reply to: Justin Pryzby (#2)
Re: UPDATE operation terminates logical replication receiver process due to an assertion

Justin Pryzby <pryzby@telsasoft.com> writes:

On Thu, Jan 12, 2023 at 01:23:57PM +0300, v.davydov@postgrespro.ru wrote:

TRAP: FailedAssertion("relinfo->ri_GeneratedExprs != NULL", File: "execUtils.c", Line: 1292)

Yeah, confirmed under master branch and v15.

v15? That assert is from 8bf6ec3ba, which wasn't back-patched.

regards, tom lane

#5Justin Pryzby
pryzby@telsasoft.com
In reply to: Tom Lane (#4)
Re: UPDATE operation terminates logical replication receiver process due to an assertion

On Sun, Jan 15, 2023 at 01:25:11PM -0500, Tom Lane wrote:

Justin Pryzby <pryzby@telsasoft.com> writes:

On Thu, Jan 12, 2023 at 01:23:57PM +0300, v.davydov@postgrespro.ru wrote:

TRAP: FailedAssertion("relinfo->ri_GeneratedExprs != NULL", File: "execUtils.c", Line: 1292)

Yeah, confirmed under master branch and v15.

v15? That assert is from 8bf6ec3ba, which wasn't back-patched.

I misspoke, and had actually reproduced under master and v14:

TRAP: FailedAssertion("relinfo->ri_GeneratedExprs != NULL", File: "execUtils.c", Line: 1336, PID: 25692)

The assert isn't from 8bf6 (Improve handling of inherited GENERATED
expressions.), but rather:

commit 3f7836ff651ad710fef52fa87b248ecdfc6468dc
Author: Tom Lane <tgl@sss.pgh.pa.us>
Date: Thu Jan 5 14:12:17 2023 -0500

Fix calculation of which GENERATED columns need to be updated.

And in v14:
commit 8cd190e13a22dab12e86f7f1b59de6b9b128c784
Author: Tom Lane <tgl@sss.pgh.pa.us>
Date: Thu Jan 5 14:12:17 2023 -0500

Fix calculation of which GENERATED columns need to be updated.

--
Justin

#6Tom Lane
tgl@sss.pgh.pa.us
In reply to: Justin Pryzby (#5)
Re: UPDATE operation terminates logical replication receiver process due to an assertion

Justin Pryzby <pryzby@telsasoft.com> writes:

On Sun, Jan 15, 2023 at 01:25:11PM -0500, Tom Lane wrote:

v15? That assert is from 8bf6ec3ba, which wasn't back-patched.

The assert isn't from 8bf6 (Improve handling of inherited GENERATED
expressions.), but rather:

commit 3f7836ff651ad710fef52fa87b248ecdfc6468dc

Ah. I jumped to the wrong conclusion after failing to reproduce
on v15, but I must've fat-fingered the test case somehow.

regards, tom lane