Received: from malur.postgresql.org ([217.196.149.56]) by arkaria.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1khvww-0006K2-M3 for pgsql-hackers@arkaria.postgresql.org; Wed, 25 Nov 2020 14:39:15 +0000 Received: from localhost ([127.0.0.1] helo=malur.postgresql.org) by malur.postgresql.org with esmtp (Exim 4.92) (envelope-from ) id 1khvwv-0005Ge-Jh for pgsql-hackers@arkaria.postgresql.org; Wed, 25 Nov 2020 14:39:13 +0000 Received: from makus.postgresql.org ([2001:4800:3e1:1::229]) by malur.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_256_GCM_SHA384:256) (Exim 4.92) (envelope-from ) id 1khvwv-0005GW-2h for pgsql-hackers@lists.postgresql.org; Wed, 25 Nov 2020 14:39:13 +0000 Received: from mail-pf1-x42e.google.com ([2607:f8b0:4864:20::42e]) by makus.postgresql.org with esmtps (TLS1.3:ECDHE_RSA_AES_128_GCM_SHA256:128) (Exim 4.92) (envelope-from ) id 1khvws-00058h-2b for pgsql-hackers@postgresql.org; Wed, 25 Nov 2020 14:39:11 +0000 Received: by mail-pf1-x42e.google.com with SMTP id w6so2533886pfu.1 for ; Wed, 25 Nov 2020 06:39:09 -0800 (PST) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=mime-version:references:in-reply-to:from:date:message-id:subject:to :cc; bh=reGBYhYu9s88KdjHCdH5zGb35skA05KQhf0byIqEFu8=; b=HKFOL7vNVlConi7HgT0jUg9rCt3ZOgIIoTTynMAuQf21saahwIqOTusRIjkMab1YMl v6u01pLXel+Y8zcAWIPWWhoXcydQCma3WtcxlZuVYPFb0BW0nQ9JT715hAp90FIJP/sM QLYv0pEWrFgXW4WC2+/r+Y/FMk4IQ9q25jiiEspM/mjMb7c2rdaW8AcbJVxZWU4kT1Lf dx239gEIhuqf+fDau1yrUUD5XfcGlIQMNqgIFTsF5JPwXz/UJYg/ZKGrrRJ/5Scs1uT2 ys0JqoJdLZXulAcC3Xn0YnBCQE/XthUaiFmTe+H4IZ7F6k8vHlZLVefoc89k6VnrO6xI Ohjw== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:mime-version:references:in-reply-to:from:date :message-id:subject:to:cc; bh=reGBYhYu9s88KdjHCdH5zGb35skA05KQhf0byIqEFu8=; b=Pnx3pxoEspPjr0ObcNTJwnrVo6vMzgIE1V0ATLw3iEPS2TnO8dV23z3Xq6QF2oCvdu F9Z7hkTA19pclChmA27vVODwiYoq6982nqInKztMmHIq+ToWNAoweLWzvVBiOHfUGVX4 WUz7df3gESzu3ZyFIEjxEd7bEXrZQTqryVJf8OWguu3iv2AWAlG3JLxqggXkmP0P9O/X gxxe27p+Jt8LutDSp/VJR889vxmtG1kzaCTWJPlF1H2eD5BiPkFYtg7u5db2nV0UOym7 8hfFMl9YhuLVvSPuAZf7lviP3AC0IIl8P73iCIvRvFF6u3oKSK6LSz3cXP0AaWKut5W4 vVvA== X-Gm-Message-State: AOAM533H67ym+oCqo+4CszbWz7Z3S9zZz0CgwQQrakr98tOxGLTb1+Zq ANOQHKTFP/0+HrN6RuaQpXoLRmWLPPnHtp7976o= X-Google-Smtp-Source: ABdhPJwpnLWzTL47gGx7ICrAtoXPcxFfPTdCbYSgzltarbaaYFzYKPBaZPZ6bEX9EaUU4yNQUQENYPyZeqsrLdIIwZI= X-Received: by 2002:a17:90a:c201:: with SMTP id e1mr4507801pjt.16.1606315148727; Wed, 25 Nov 2020 06:39:08 -0800 (PST) MIME-Version: 1.0 References: <13156732-5189-af54-3d28-e2ee2a8568e0@oss.nttdata.com> <069fb3bc-3907-4d85-19fd-e4b2d2f004b4@oss.nttdata.com> <1ae40b1b-2f42-4510-1514-40bb7d7255ab@oss.nttdata.com> <3f292fbb-f155-9a01-7cb2-7ccc9007ab3f@oss.nttdata.com> In-Reply-To: <3f292fbb-f155-9a01-7cb2-7ccc9007ab3f@oss.nttdata.com> From: Bharath Rupireddy Date: Wed, 25 Nov 2020 20:08:57 +0530 Message-ID: Subject: Re: Use standard SIGHUP and SIGTERM handlers in autoprewarm module To: Fujii Masao Cc: Craig Ringer , PostgreSQL-development , Robert Haas Content-Type: multipart/alternative; boundary="000000000000d65b0c05b4ef633c" List-Id: List-Help: List-Subscribe: List-Post: List-Owner: List-Archive: Precedence: bulk --000000000000d65b0c05b4ef633c Content-Type: text/plain; charset="UTF-8" On Wed, Nov 25, 2020 at 3:29 PM Fujii Masao wrote: > > On 2020/11/20 19:33, Bharath Rupireddy wrote: > > On Wed, Nov 18, 2020 at 5:52 PM Fujii Masao > wrote: > > > > > > > handle_sigterm() and die() are similar except that die() has extra > > > > handling(below) for exiting immediately when waiting for input/command > > > > from the client. > > > > /* > > > > * If we're in single user mode, we want to quit immediately - we can't > > > > * rely on latches as they wouldn't work when stdin/stdout is a file. > > > > * Rather ugly, but it's unlikely to be worthwhile to invest much more > > > > * effort just for the benefit of single user mode. > > > > */ > > > > if (DoingCommandRead && whereToSendOutput != DestRemote) > > > > ProcessInterrupts(); > > > > > > > > Having this extra handling is correct for normal backends as they can > > > > connect directly to clients for reading input commands, the above if > > > > condition may become true and ProcessInterrupts() may be called to > > > > handle the SIGTERM immediately. > > > > > > > > Note that DoingCommandRead can never be true in bg workers as it's > > > > being set to true only in normal backend PostgresMain(). If we use > > > > die()(instead of custom SIGTERM handlers such as handle_sigterm()) in > > > > a bg worker/non-backend process, there are no chances that the above > > > > part of the code gets hit and the interrupts are processed > > > > immediately. And also here are the bg worker process that use die() > > > > instead of their own custom handlers: parallel workers, autoprewarm > > > > worker, autovacuum worker, logical replication launcher and apply > > > > worker, wal sender process > > > > > > > > I think we can also use die() instead of handle_sigterm() in > > > > test_shm_mq/worker.c. > > > > > > > > I attached a patch for this change. > > > > > > Thanks for the patch! It looks good to me. > > > > > > > Thanks. > > When I read the patch again, I found that, with the patch, the shutdown > of worker_spi causes to report the following FATAL message. > > FATAL: terminating connection due to administrator command > > Isn't this message confusing because it's not a connection? If so, > we need to update ProcessInterrupts() so that the proper message is > reported like other bgworkers do. > This is also true for all the bgworker that use the die() handler. How about doing it the way bgworker_die() does in ProcessInterrupts()? This would give meaningful information. Thoughts? If okay, I can make a separate patch. else if (RecoveryConflictPending) { /* Currently there is only one non-retryable recovery conflict */ Assert(RecoveryConflictReason == PROCSIG_RECOVERY_CONFLICT_DATABASE); pgstat_report_recovery_conflict(RecoveryConflictReason); ereport(FATAL, (errcode(ERRCODE_DATABASE_DROPPED), errmsg("terminating connection due to conflict with recovery"), errdetail_recovery_conflict())); } * else if (IsBackgroundWorker) { ereport(FATAL, (errcode(ERRCODE_ADMIN_SHUTDOWN), errmsg("terminating background worker \"%s\" due to administrator command", MyBgworkerEntry->bgw_type))); }* else ereport(FATAL, (errcode(ERRCODE_ADMIN_SHUTDOWN), errmsg("terminating connection due to administrator command"))); > > BTW, though this is not directly related to this topic, it's strange to me > that the normal shutdown of bgworker causes to emit FATAL message > and the message "background worker ... exited with exit code 1" > at the normal shutdown. I've heard sometimes that users coplained that > it's confusing to report that message for logical replication launcher > at the normal shutdown. Maybe the mechanism to shutdown bgworker > normally seems to have not been implemented well yet. > What do you mean by normal shutdown of bgworker? Is it that bgworker has exited successfully with exit code 0 or for some reason with exit code other than 0? Or is it when the postmaster is shutdown normally? IIUC, when a bgworker exists either normally with an exit code 0 or other than 0, then CleanupBackgroundWorker() is called in postmaster, a message(like below) is prepared, and the LogChildExit() is called with either DEBUG1 or LOG level and for instance the message you specified gets printed "background worker ... exited with exit code 1". I have not seen a FATAL message similar to "background worker ... exited with exit code 1" at the normal shutdown. snprintf(namebuf, MAXPGPATH, _("background worker \"%s\""), rw->rw_worker.bgw_type); LogChildExit(EXIT_STATUS_0(exitstatus) ? DEBUG1 : LOG, namebuf, pid, exitstatus); Am I missing something? If my analysis is right, then for instance, when a logical replication launcher is exited, it logs "background worker "logical replication launcher" exited with exit code X" with either DEBUG1 or LOG level but not with FATAL level. > > Without the patch, since worker_spi cannot handle the shutdown request > promptly while it's executing the backend code, maybe we can say this is > a bug. But worker_spi is a just example of the code, I'm not thinking to > do back-patch for now. Thought? > +1 to not backpatch it. With Regards, Bharath Rupireddy. EnterpriseDB: http://www.enterprisedb.com --000000000000d65b0c05b4ef633c Content-Type: text/html; charset="UTF-8" Content-Transfer-Encoding: quoted-printable
On Wed, Nov 25, 2020 at 3:29 PM Fujii Masao <masao.fujii@oss.nttdata.com> wr= ote:
>
> On 2020/11/20 19:33, Bharath Rupireddy wrote:
> = > On Wed, Nov 18, 2020 at 5:52 PM Fujii Masao <masao.fujii@oss.nttdata.com <mailto:masao.fujii@oss.nttdata.com>= > wrote:
> > =C2=A0>
> > =C2=A0> > handle_sig= term() and die() are similar except that die() has extra
> > =C2= =A0> > handling(below) for exiting immediately when waiting for input= /command
> > =C2=A0> > from the client.
> > =C2=A0&= gt; > =C2=A0 =C2=A0 =C2=A0/*
> > =C2=A0> > =C2=A0 =C2=A0 = =C2=A0 * If we're in single user mode, we want to quit immediately - we= can't
> > =C2=A0> > =C2=A0 =C2=A0 =C2=A0 * rely on latc= hes as they wouldn't work when stdin/stdout is a file.
> > =C2= =A0> > =C2=A0 =C2=A0 =C2=A0 * Rather ugly, but it's unlikely to b= e worthwhile to invest much more
> > =C2=A0> > =C2=A0 =C2=A0= =C2=A0 * effort just for the benefit of single user mode.
> > =C2= =A0> > =C2=A0 =C2=A0 =C2=A0 */
> > =C2=A0> > =C2=A0 = =C2=A0 =C2=A0if (DoingCommandRead && whereToSendOutput !=3D DestRem= ote)
> > =C2=A0> > =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0Process= Interrupts();
> > =C2=A0> >
> > =C2=A0> > Hav= ing this extra handling is correct for normal backends as they can
> = > =C2=A0> > connect directly to clients for reading input commands= , the above if
> > =C2=A0> > condition may become true and P= rocessInterrupts() may be called to
> > =C2=A0> > handle the= SIGTERM immediately.
> > =C2=A0> >
> > =C2=A0> = > Note that DoingCommandRead can never be true in bg workers as it's=
> > =C2=A0> > being set to true only in normal backend Post= gresMain(). If we use
> > =C2=A0> > die()(instead of custom = SIGTERM handlers such as handle_sigterm()) in
> > =C2=A0> > = a bg worker/non-backend process, there are no chances that the above
>= ; > =C2=A0> > part of the code gets hit and the interrupts are pro= cessed
> > =C2=A0> > immediately. And also here are the bg w= orker process that use die()
> > =C2=A0> > instead of their = own custom handlers: parallel workers, autoprewarm
> > =C2=A0> = > worker, autovacuum worker, logical replication launcher and apply
&= gt; > =C2=A0> > worker, wal sender process
> > =C2=A0>= >
> > =C2=A0> > I think we can also use die() instead of= handle_sigterm() in
> > =C2=A0> > test_shm_mq/worker.c.
= > > =C2=A0> >
> > =C2=A0> > I attached a patch f= or this change.
> > =C2=A0>
> > =C2=A0> Thanks for = the patch! It looks good to me.
> > =C2=A0>
> >
>= ; > Thanks.
>
> When I read the patch again, I found that, w= ith the patch, the shutdown
> of worker_spi causes to report the foll= owing FATAL message.
>
> =C2=A0 =C2=A0 =C2=A0FATAL: =C2=A0termi= nating connection due to administrator command
>
> Isn't th= is message confusing because it's not a connection? If so,
> we n= eed to update ProcessInterrupts() so that the proper message is
> rep= orted like other bgworkers do.
>

This is also true for all the= bgworker that use the die() handler. How about doing it the way bgworker_d= ie() does in ProcessInterrupts()? This would give meaningful information. T= houghts? If okay, I can make a separate patch.

=C2=A0 =C2=A0 =C2=A0 = =C2=A0 else if (RecoveryConflictPending)
=C2=A0 =C2=A0 =C2=A0 =C2=A0 {=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 /* Currently there is only one = non-retryable recovery conflict */
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 = =C2=A0 Assert(RecoveryConflictReason =3D=3D PROCSIG_RECOVERY_CONFLICT_DATAB= ASE);
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 pgstat_report_recovery_c= onflict(RecoveryConflictReason);
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2= =A0 ereport(FATAL,
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0 (errcode(ERRCODE_DATABASE_DROPPED),
=C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0errmsg("ter= minating connection due to conflict with recovery"),
=C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0errdetail_rec= overy_conflict()));
=C2=A0 =C2=A0 =C2=A0 =C2=A0 }
=C2=A0 =C2=A0 =C2=A0 =C2=A0else if (IsBackgroundWorker)<= br>=C2=A0 =C2=A0 =C2=A0 =C2=A0{
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0ereport(FATAL,
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0(errcode(ERRCODE= _ADMIN_SHUTDOWN),
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2= =A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 errmsg("terminating back= ground worker \"%s\" due to administrator command",
=C2= =A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A0 MyBgworkerEntry->bgw_type)));
=C2=A0 =C2=A0 =C2= =A0 =C2=A0}
=C2=A0 =C2=A0 =C2=A0 =C2=A0 else
=C2=A0 =C2=A0= =C2=A0 =C2=A0 =C2=A0 =C2=A0 ereport(FATAL,
=C2=A0 =C2=A0 =C2=A0 =C2=A0 = =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 (errcode(ERRCODE_ADMIN_SHUTDOWN),=
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 = =C2=A0errmsg("terminating connection due to administrator command"= ;)));

>
> BTW, though this is not directly related to this = topic, it's strange to me
> that the normal shutdown of bgworker = causes to emit FATAL message
> and the message "background worke= r ... exited with exit code 1"
> at the normal shutdown. I'v= e heard sometimes that users coplained that
> it's confusing to r= eport that message for logical replication launcher
> at the normal s= hutdown. Maybe the mechanism to shutdown bgworker
> normally seems to= have not been implemented well yet.
>

= What do you mean by normal shutdown of bgworker? Is it that bgworker has ex= ited successfully with exit code 0 or for some reason with exit code other = than 0? Or is it when the postmaster is shutdown normally?
IIUC, when a bgworker exists either normally with an exit code= 0 or other than 0, then CleanupBackgroundWorker() is called in postmaster,= a message(like below) is prepared, and the LogChildExit() is called with e= ither DEBUG1 or LOG level and for instance the message you specified gets p= rinted "background worker ... exited with exit code 1". I have n= ot seen a FATAL message similar to "background worker ... exited with = exit code 1" at the normal shutdown.

snpr= intf(namebuf, MAXPGPATH, _("background worker \"%s\""),= rw->rw_worker.bgw_type);

LogChildExit(EXIT_STA= TUS_0(exitstatus) ? DEBUG1 : LOG, namebuf, pid, exitstatus);

=
Am I missing something?

If my analysis = is right, then for instance, when a logical replication launcher is exited,= it logs "background worker "logical replication launcher" = exited with exit code X" with either DEBUG1 or LOG level but not with = FATAL level.

>
> Without the patch, since = worker_spi cannot handle the shutdown request
> promptly while it'= ;s executing the backend code, maybe we can say this is
> a bug. But = worker_spi is a just example of the code, I'm not thinking to
> d= o back-patch for now. Thought?
>

+1 to = not backpatch it.

With Regards,
Bharath Rup= ireddy.
EnterpriseDB: http://www= .enterprisedb.com

--000000000000d65b0c05b4ef633c--