Обсуждение: BUG #17789: process_pgfdw_appname() fails for autovacuum workers

The following bug has been logged on the website:

Bug reference:      17789
Logged by:          Alexander Lakhin
Email address:      exclusion@gmail.com
PostgreSQL version: 15.2
Operating system:   Ubuntu 22.04
Description:

When executing the following queries:
CREATE EXTENSION postgres_fdw;
DO $d$
        BEGIN
            EXECUTE $$CREATE SERVER loopback FOREIGN DATA WRAPPER
postgres_fdw
                OPTIONS (dbname '$$||current_database()||$$',
                         port '$$||current_setting('port')||$$'
                )$$;
        END;
    $d$;
CREATE USER MAPPING FOR CURRENT_USER SERVER loopback;
ALTER SERVER loopback OPTIONS (application_name 'postgres_fdw %d/%u');
CREATE TABLE t1 (a int);
INSERT INTO t1 SELECT * FROM generate_series(1, 66) i;
CREATE FOREIGN TABLE ft1 (b int) INHERITS (t1)
      SERVER LOOPBACK OPTIONS (table_name 'anytable');
\c -
SELECT pg_sleep(60)

with the autovacuum enabled:
autovacuum = on
autovacuum_naptime = 1
autovacuum_vacuum_threshold = 1

I get an assertion failure:
Core was generated by `postgres: autovacuum worker regression
                        '.
Program terminated with signal SIGABRT, Aborted.

warning: Section `.reg-xstate/2522086' in core file too small.
#0  __pthread_kill_implementation (no_tid=0, signo=6,
threadid=140402663786304) at ./nptl/pthread_kill.c:44
44      ./nptl/pthread_kill.c: No such file or directory.
(gdb) bt
#0  __pthread_kill_implementation (no_tid=0, signo=6,
threadid=140402663786304) at ./nptl/pthread_kill.c:44
#1  __pthread_kill_internal (signo=6, threadid=140402663786304) at
./nptl/pthread_kill.c:78
#2  __GI___pthread_kill (threadid=140402663786304, signo=signo@entry=6) at
./nptl/pthread_kill.c:89
#3  0x00007fb20a30e476 in __GI_raise (sig=sig@entry=6) at
../sysdeps/posix/raise.c:26
#4  0x00007fb20a2f47f3 in __GI_abort () at ./stdlib/abort.c:79
#5  0x0000564b2ecc55c8 in ExceptionalCondition
(conditionName=conditionName@entry=0x7fb1feb3f81e "MyProcPort != NULL", 
    errorType=errorType@entry=0x7fb1feb3e700 "FailedAssertion",
fileName=fileName@entry=0x7fb1feb3f75a "option.c", 
    lineNumber=lineNumber@entry=464) at assert.c:69
#6  0x00007fb1feb31b30 in process_pgfdw_appname (appname=<optimized out>) at
option.c:464
#7  0x00007fb1feb2ae40 in connect_pg_server
(server=server@entry=0x564b30b0c220, user=user@entry=0x564b30b0c0b0)
    at connection.c:416
#8  0x00007fb1feb2b2be in make_new_connection
(entry=entry@entry=0x564b30b203d0, user=user@entry=0x564b30b0c0b0)
    at connection.c:344
#9  0x00007fb1feb2b799 in GetConnection (user=0x564b30b0c0b0,
will_prep_stmt=will_prep_stmt@entry=false, 
    state=state@entry=0x0) at connection.c:204
#10 0x00007fb1feb34a44 in postgresAnalyzeForeignTable
(relation=0x7fb1feb4fa30, func=<optimized out>, 
    totalpages=0x7fff7f91b4a8) at postgres_fdw.c:4951
#11 0x0000564b2e916252 in acquire_inherited_sample_rows
(onerel=onerel@entry=0x7fb1feb4b940, elevel=elevel@entry=13, 
    rows=rows@entry=0x564b30b27750, targrows=targrows@entry=30000,
totalrows=totalrows@entry=0x7fff7f91b5b0, 
    totaldeadrows=totaldeadrows@entry=0x7fff7f91b5b8) at analyze.c:1470
#12 0x0000564b2e91983f in do_analyze_rel
(onerel=onerel@entry=0x7fb1feb4b940, params=params@entry=0x564b30aaaaa4, 
    va_cols=va_cols@entry=0x0, acquirefunc=0x564b2e91854e
<acquire_sample_rows>, relpages=1, inh=inh@entry=true, 
    in_outer_xact=false, elevel=13) at analyze.c:534
#13 0x0000564b2e91a167 in analyze_rel (relid=<optimized out>,
relation=0x564b30b07250, 
    params=params@entry=0x564b30aaaaa4, va_cols=0x0,
in_outer_xact=<optimized out>, bstrategy=<optimized out>)
    at analyze.c:269
#14 0x0000564b2e9a8ec7 in vacuum (relations=0x564b30b092b8,
params=params@entry=0x564b30aaaaa4, 
    bstrategy=<optimized out>, bstrategy@entry=0x564b30b034a8,
isTopLevel=isTopLevel@entry=true) at vacuum.c:492
#15 0x0000564b2eace110 in autovacuum_do_vac_analyze
(tab=tab@entry=0x564b30aaaaa0, 
    bstrategy=bstrategy@entry=0x564b30b034a8) at autovacuum.c:3149
#16 0x0000564b2ead028a in do_autovacuum () at autovacuum.c:2472
#17 0x0000564b2ead07ce in AutoVacWorkerMain (argc=argc@entry=0,
argv=argv@entry=0x0) at autovacuum.c:1715
#18 0x0000564b2ead08ac in StartAutoVacWorker () at autovacuum.c:1493
#19 0x0000564b2ead8300 in StartAutovacuumWorker () at postmaster.c:5541
#20 0x0000564b2ead932f in sigusr1_handler (postgres_signal_arg=<optimized
out>) at postmaster.c:5246
#21 <signal handler called>
#22 0x00007fb20a3e774d in __GI___select (nfds=nfds@entry=8,
readfds=readfds@entry=0x7fff7f91c960, 
    writefds=writefds@entry=0x0, exceptfds=exceptfds@entry=0x0,
timeout=timeout@entry=0x7fff7f91c8d0)
    at ../sysdeps/unix/sysv/linux/select.c:69
#23 0x0000564b2ead999d in ServerLoop () at postmaster.c:1770
#24 0x0000564b2eadad45 in PostmasterMain (argc=argc@entry=3,
argv=argv@entry=0x564b30a29620) at postmaster.c:1478
#25 0x0000564b2ea1f2b0 in main (argc=3, argv=0x564b30a29620) at main.c:202

(A build without asserts crashes with a segmentation fault for me.)
Observed on REL_15_STABLE..master since the process_pgfdw_appname()
introduction (6e0cb3de).
Maybe the assert should be replaced by checks for MyProcPort in cases
'd','u' for compatibility with autovacuum workers.

At Mon, 13 Feb 2023 05:00:01 +0000, PG Bug reporting form <noreply@postgresql.org> wrote in 
> CREATE FOREIGN TABLE ft1 (b int) INHERITS (t1)
>       SERVER LOOPBACK OPTIONS (table_name 'anytable');

Yeah, the autovacuum processes t1 and then its child foreign table
ft1. MyProcPort is NULL on autovacuum processes. This doesn't happen
for partitioned tables.

> #5  0x0000564b2ecc55c8 in ExceptionalCondition
> (conditionName=conditionName@entry=0x7fb1feb3f81e "MyProcPort != NULL", 
>     errorType=errorType@entry=0x7fb1feb3e700 "FailedAssertion",
> fileName=fileName@entry=0x7fb1feb3f75a "option.c", 
>     lineNumber=lineNumber@entry=464) at assert.c:69
> #6  0x00007fb1feb31b30 in process_pgfdw_appname (appname=<optimized out>) at
> option.c:464

Commit 6e0cb3dec1 overlooked the case of autovacuum analyzing foreign
tables as an inheritance child. We thought NULL MyProcPort was
impossible in the discussion for the patch. Using %d and %u in
postgres_fdw.application_name we hit the bug.

The following change fixes the bug.

- Is it okay to use '-' as %u (user name) and %d (databsae name) in
  the NULL MyProcPort case?

- Do we need tests for the case? They need to wait for autovacuum to run.



diff --git a/contrib/postgres_fdw/option.c b/contrib/postgres_fdw/option.c
index 984e4d168a..b6239a46a3 100644
--- a/contrib/postgres_fdw/option.c
+++ b/contrib/postgres_fdw/option.c
@@ -485,8 +485,6 @@ process_pgfdw_appname(const char *appname)
     const char *p;
     StringInfoData buf;
 
-    Assert(MyProcPort != NULL);
-
     initStringInfo(&buf);
 
     for (p = appname; *p != '\0'; p++)
@@ -522,13 +520,21 @@ process_pgfdw_appname(const char *appname)
                 appendStringInfoString(&buf, cluster_name);
                 break;
             case 'd':
-                appendStringInfoString(&buf, MyProcPort->database_name);
+                /* MyProcPort can be NULL on autovacuum proces */
+                if (MyProcPort)
+                    appendStringInfoString(&buf, MyProcPort->database_name);
+                else
+                    appendStringInfoChar(&buf, '-');
                 break;
             case 'p':
                 appendStringInfo(&buf, "%d", MyProcPid);
                 break;
             case 'u':
-                appendStringInfoString(&buf, MyProcPort->user_name);
+                if (MyProcPort)
+                    appendStringInfoString(&buf, MyProcPort->user_name);
+                else
+                    appendStringInfoChar(&buf, '-');
+                    
                 break;
             default:
                 /* format error - ignore it */

-- 
Kyotaro Horiguchi
NTT Open Source Software Center

On Tue, Feb 14, 2023 at 2:05 PM Kyotaro Horiguchi
<horikyota.ntt@gmail.com> wrote:
>
> At Mon, 13 Feb 2023 05:00:01 +0000, PG Bug reporting form <noreply@postgresql.org> wrote in
> > CREATE FOREIGN TABLE ft1 (b int) INHERITS (t1)
> >         SERVER LOOPBACK OPTIONS (table_name 'anytable');
>
> Yeah, the autovacuum processes t1 and then its child foreign table
> ft1. MyProcPort is NULL on autovacuum processes. This doesn't happen
> for partitioned tables.
>
> > #5  0x0000564b2ecc55c8 in ExceptionalCondition
> > (conditionName=conditionName@entry=0x7fb1feb3f81e "MyProcPort != NULL",
> >     errorType=errorType@entry=0x7fb1feb3e700 "FailedAssertion",
> > fileName=fileName@entry=0x7fb1feb3f75a "option.c",
> >     lineNumber=lineNumber@entry=464) at assert.c:69
> > #6  0x00007fb1feb31b30 in process_pgfdw_appname (appname=<optimized out>) at
> > option.c:464
>
> Commit 6e0cb3dec1 overlooked the case of autovacuum analyzing foreign
> tables as an inheritance child. We thought NULL MyProcPort was
> impossible in the discussion for the patch. Using %d and %u in
> postgres_fdw.application_name we hit the bug.
>
> The following change fixes the bug.

The change seems to work fine.

>
> - Is it okay to use '-' as %u (user name) and %d (databsae name) in
>   the NULL MyProcPort case?

Another idea seems to not display anything in this case, which is
consistent with what log_status_format() does.

>
> - Do we need tests for the case? They need to wait for autovacuum to run.

Not sure it's worth having tests for that as the fix is obvious.

Regards,

-- 
Masahiko Sawada
Amazon Web Services: https://aws.amazon.com

At Tue, 14 Feb 2023 17:02:45 +0900, Masahiko Sawada <sawada.mshk@gmail.com> wrote in 
> On Tue, Feb 14, 2023 at 2:05 PM Kyotaro Horiguchi
> <horikyota.ntt@gmail.com> wrote:
> >
> > At Mon, 13 Feb 2023 05:00:01 +0000, PG Bug reporting form <noreply@postgresql.org> wrote in
> > > CREATE FOREIGN TABLE ft1 (b int) INHERITS (t1)
> > >         SERVER LOOPBACK OPTIONS (table_name 'anytable');
> >
> > Yeah, the autovacuum processes t1 and then its child foreign table
> > ft1. MyProcPort is NULL on autovacuum processes. This doesn't happen
> > for partitioned tables.
> >
> > > #5  0x0000564b2ecc55c8 in ExceptionalCondition
> > > (conditionName=conditionName@entry=0x7fb1feb3f81e "MyProcPort != NULL",
> > >     errorType=errorType@entry=0x7fb1feb3e700 "FailedAssertion",
> > > fileName=fileName@entry=0x7fb1feb3f75a "option.c",
> > >     lineNumber=lineNumber@entry=464) at assert.c:69
> > > #6  0x00007fb1feb31b30 in process_pgfdw_appname (appname=<optimized out>) at
> > > option.c:464
> >
> > Commit 6e0cb3dec1 overlooked the case of autovacuum analyzing foreign
> > tables as an inheritance child. We thought NULL MyProcPort was
> > impossible in the discussion for the patch. Using %d and %u in
> > postgres_fdw.application_name we hit the bug.
> >
> > The following change fixes the bug.
> 
> The change seems to work fine.

Thanks for veryfiying that!

> > - Is it okay to use '-' as %u (user name) and %d (databsae name) in
> >   the NULL MyProcPort case?
> 
> Another idea seems to not display anything in this case, which is
> consistent with what log_status_format() does.

As you said, when MyProcPort is NULL, the function won't insert
anything unless padding is specified. But in this case, padding isn't
even a thing. So it seems best to not insert anything.

By the way, when we designed that part, we first concluded that the
user name and database name cannot be NULL before we later concluded
that MyProcPort cannot be NULL. However, log_status_format() takes
into account the case where MyProcPort stores NULL as user and
database names.  Do you think we should still ignore the case of NULL
user name and database names, even though our assumption about
MyProcPort was found to be incorrect? In that case,
log_status_format() replaces, for example, %u with '[unknown]'.

> > - Do we need tests for the case? They need to wait for autovacuum to run.
> 
> Not sure it's worth having tests for that as the fix is obvious.

Thanks you for sharing your thoughts.  I'll go with that.

regards.

-- 
Kyotaro Horiguchi
NTT Open Source Software Center

On Wed, Feb 15, 2023 at 04:12:54PM +0900, Kyotaro Horiguchi wrote:
> By the way, when we designed that part, we first concluded that the
> user name and database name cannot be NULL before we later concluded
> that MyProcPort cannot be NULL. However, log_status_format() takes
> into account the case where MyProcPort stores NULL as user and
> database names.  Do you think we should still ignore the case of NULL
> user name and database names, even though our assumption about
> MyProcPort was found to be incorrect? In that case,
> log_status_format() replaces, for example, %u with '[unknown]'.

Hmm.  I think that I would play it safe but consistent here for %d and
%u as this code could be triggered in various contexts as far as I
understand:
- When MyProcPort is NULL, insert no data, because there is nothing to
report.
- When MyProcPort is not NULL but the %d or %u field is NULL, use
[unknown], because we just don't know what to show up, still there is
a MyProcPort.

This has the advantage to be able to make the difference in both
cases, which could be important for the end-user depending on the
context where the code is run.
--
Michael

On Mon, Feb 20, 2023 at 04:59:25PM +0900, Michael Paquier wrote:
> This has the advantage to be able to make the difference in both
> cases, which could be important for the end-user depending on the
> context where the code is run.

In short, as of the attached, which is pretty close to the original
patch.
--
Michael

Dear Michael, Horiguchi-san,

Sorry for being late.

Our first assumption was broken, so I think we should consider like that
we have missed further thing.

We should chose safer one, I +1 the Michael's idea.

Best Regards,
Hayato Kuroda
FUJITSU LIMITED

At Tue, 21 Feb 2023 01:05:47 +0000, "Hayato Kuroda (Fujitsu)" <kuroda.hayato@fujitsu.com> wrote in 
> Dear Michael, Horiguchi-san,
> 
> Sorry for being late.
> 
> Our first assumption was broken, so I think we should consider like that
> we have missed further thing. 
> 
> We should chose safer one, I +1 the Michael's idea.

+1. It looks good to me.

regards.

-- 
Kyotaro Horiguchi
NTT Open Source Software Center

On Tue, Feb 21, 2023 at 1:36 PM Kyotaro Horiguchi
<horikyota.ntt@gmail.com> wrote:
>
> At Tue, 21 Feb 2023 01:05:47 +0000, "Hayato Kuroda (Fujitsu)" <kuroda.hayato@fujitsu.com> wrote in
> > Dear Michael, Horiguchi-san,
> >
> > Sorry for being late.
> >
> > Our first assumption was broken, so I think we should consider like that
> > we have missed further thing.
> >
> > We should chose safer one, I +1 the Michael's idea.
>
> +1. It looks good to me.
>

Thank you for the patch. LGTM.

Regards,

-- 
Masahiko Sawada
Amazon Web Services: https://aws.amazon.com

On Tue, Feb 21, 2023 at 03:34:43PM +0900, Masahiko Sawada wrote:
> Thank you for the patch. LGTM.

Thanks for the feedback, all.  Applied then.  (Yesterday my time, as
of 8427ce4, not today, and I forgot to update this thread).
--
Michael

At Wed, 22 Feb 2023 10:07:58 +0900, Michael Paquier <michael@paquier.xyz> wrote in 
> On Tue, Feb 21, 2023 at 03:34:43PM +0900, Masahiko Sawada wrote:
> > Thank you for the patch. LGTM.
> 
> Thanks for the feedback, all.  Applied then.  (Yesterday my time, as
> of 8427ce4, not today, and I forgot to update this thread).

Thanks all!

regards.

-- 
Kyotaro Horiguchi
NTT Open Source Software Center