Обсуждение: UPDATE operation terminates logical replication receiver process due to an assertion

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

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

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

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

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

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