pg.ddx.io  pgsql-hackers@postgresql.org mailing list archive  
help / color / mirror / Atom feed
when the startup process doesn't
38+ messages / 12 participants
[nested] [flat]

Commits from this thread:
  2021-10-25 9ce346eabf  Report progress of startup operations that take a long time.
* when the startup process doesn't
@ 2021-04-19 17:55 Robert Haas <robertmhaas@gmail.com>
  2021-04-19 23:16 ` Re: when the startup process doesn't Alvaro Herrera <alvherre@alvh.no-ip.org>
  2021-04-20 00:30 ` Re: when the startup process doesn't Bruce Momjian <bruce@momjian.us>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 12:22 ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 20:28 ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-20 21:11 ` Re: when the startup process doesn't SATYANARAYANA NARLAPURAM <satyanarlapuram@gmail.com>
  0 siblings, 6 replies; 38+ messages in thread

From: Robert Haas @ 2021-04-19 17:55 UTC (permalink / raw)
  To: pgsql-hackers

Hi,

I've noticed that customers not infrequently complain that they start
postgres and then the system doesn't come up for a while and they have
no idea what's going on and are (understandably) worried. There are
probably a number of reasons why this can happen, but the ones that
seem to come up most often in my experience are (1) SyncDataDirectory
takes a long time, (b) ResetUnloggedRelations takes a long time, and
(c) there's a lot of WAL to apply so that takes a long time. It's
possible to distinguish this last case from the other two by looking
at the output of 'ps', but that's not super-convenient if your normal
method of access to the server is via libpq, and it only works if you
are monitoring it as it's happening rather than looking at the logs
after-the-fact. I am not sure there's any real way to distinguish the
other two cases without using strace or gdb or similar.

It seems to me that we could do better. One approach would be to try
to issue a log message periodically - maybe once per minute, or some
configurable interval, e.g. perhaps add messages something like this:

LOG:  still syncing data directory, elapsed time %ld.%03d ms, current path %s
LOG:  data directory sync complete after %ld.%03d ms
LOG:  still resetting unlogged relations, elapsed time %ld.%03d ms,
current path %s
LOG:  unlogged relations reset after %ld.%03d ms
LOG:  still performing crash recovery, elapsed time %ld.%03d ms,
current LSN %08X/%08X

We already have a message when redo is complete, so there's no need
for another one. The implementation here doesn't seem too hard either:
the startup process would set a timer, when the timer expires the
signal handler sets a flag, at a convenient point we notice the flag
is set and responding by printing a message and clearing the flag.

Another possible approach would be to accept connections for
monitoring purposes even during crash recovery. We can't allow access
to any database at that point, since the system might not be
consistent, but we could allow something like a replication connection
(the non-database-associated variant). Maybe it would be precisely a
replication connection and we'd just refuse all but a subset of
commands, or maybe it would be some other kinds of thing. But either
way you'd be able to issue a command in some mini-language saying "so,
tell me how startup is going" and it would reply with a result set of
some kind.

If I had to pick one of these two ideas, I'd pick the one the
log-based solution, since it seems easier to access and simplifies
retrospective analysis, but I suspect SQL access would be quite useful
for some users too, especially in cloud environments where "just log
into the machine and have a look" is not an option.

Thoughts?

-- 
Robert Haas
EDB: http://www.enterprisedb.com





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
@ 2021-04-19 23:16 ` Alvaro Herrera <alvherre@alvh.no-ip.org>
  5 siblings, 0 replies; 38+ messages in thread

From: Alvaro Herrera @ 2021-04-19 23:16 UTC (permalink / raw)
  To: Robert Haas <robertmhaas@gmail.com>; +Cc: pgsql-hackers

On 2021-Apr-19, Robert Haas wrote:

> Another possible approach would be to accept connections for
> monitoring purposes even during crash recovery. We can't allow access
> to any database at that point, since the system might not be
> consistent, but we could allow something like a replication connection
> (the non-database-associated variant).

Hmm.  We already have pg_isready, which is pretty simplistic -- it tries
to connect to the server and derive a status in a very simplistic way.
Can we perhaps improve on that?  I think your idea of using the
non-database-connected replication mode would let the server return a
tuple with some status information with a new command.  And then
pg_isready could interpret that, or just print it.

-- 
Álvaro Herrera                            39°49'30"S 73°17'W
Subversion to GIT: the shortest path to happiness I've ever heard of
                                                (Alexey Klyukin)





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
@ 2021-04-20 00:30 ` Bruce Momjian <bruce@momjian.us>
  5 siblings, 0 replies; 38+ messages in thread

From: Bruce Momjian @ 2021-04-20 00:30 UTC (permalink / raw)
  To: Robert Haas <robertmhaas@gmail.com>; +Cc: pgsql-hackers

On Mon, Apr 19, 2021 at 01:55:13PM -0400, Robert Haas wrote:
> I've noticed that customers not infrequently complain that they start
> postgres and then the system doesn't come up for a while and they have
> no idea what's going on and are (understandably) worried. There are
> probably a number of reasons why this can happen, but the ones that
> seem to come up most often in my experience are (1) SyncDataDirectory
> takes a long time, (b) ResetUnloggedRelations takes a long time, and
> (c) there's a lot of WAL to apply so that takes a long time. It's
> possible to distinguish this last case from the other two by looking
> at the output of 'ps', but that's not super-convenient if your normal
> method of access to the server is via libpq, and it only works if you
> are monitoring it as it's happening rather than looking at the logs
> after-the-fact. I am not sure there's any real way to distinguish the
> other two cases without using strace or gdb or similar.
> 
> It seems to me that we could do better. One approach would be to try
> to issue a log message periodically - maybe once per minute, or some
> configurable interval, e.g. perhaps add messages something like this:

Yes, this certainly needs improvement.

-- 
  Bruce Momjian  <bruce@momjian.us>        https://momjian.us
  EDB                                      https://enterprisedb.com

  If only the physical world exists, free will is an illusion.






^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
@ 2021-04-20 00:38 ` Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  5 siblings, 1 reply; 38+ messages in thread

From: Thomas Munro @ 2021-04-20 00:38 UTC (permalink / raw)
  To: Robert Haas <robertmhaas@gmail.com>; +Cc: pgsql-hackers

On Tue, Apr 20, 2021 at 5:55 AM Robert Haas <robertmhaas@gmail.com> wrote:
> If I had to pick one of these two ideas, I'd pick the one the
> log-based solution, since it seems easier to access and simplifies
> retrospective analysis, but I suspect SQL access would be quite useful
> for some users too, especially in cloud environments where "just log
> into the machine and have a look" is not an option.

+1 for both ideas.  I've heard multiple requests for something like
that.  A couple of users with update_process_title=off told me they
regretted that choice when they found themselves running a long crash
recovery with the only indicator of progress disabled.





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
@ 2021-04-20 00:44   ` Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  0 siblings, 1 reply; 38+ messages in thread

From: Tom Lane @ 2021-04-20 00:44 UTC (permalink / raw)
  To: Thomas Munro <thomas.munro@gmail.com>; +Cc: Robert Haas <robertmhaas@gmail.com>; pgsql-hackers

Thomas Munro <thomas.munro@gmail.com> writes:
> On Tue, Apr 20, 2021 at 5:55 AM Robert Haas <robertmhaas@gmail.com> wrote:
>> If I had to pick one of these two ideas, I'd pick the one the
>> log-based solution, since it seems easier to access and simplifies
>> retrospective analysis, but I suspect SQL access would be quite useful
>> for some users too, especially in cloud environments where "just log
>> into the machine and have a look" is not an option.

> +1 for both ideas.  I've heard multiple requests for something like
> that.  A couple of users with update_process_title=off told me they
> regretted that choice when they found themselves running a long crash
> recovery with the only indicator of progress disabled.

Hmm ... +1 for progress messages in the log, but I'm suspicious about
the complexity-and-fragility-versus-value tradeoff for the other thing.

			regards, tom lane





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
@ 2021-04-20 12:43     ` Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  0 siblings, 1 reply; 38+ messages in thread

From: Robert Haas @ 2021-04-20 12:43 UTC (permalink / raw)
  To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

On Mon, Apr 19, 2021 at 8:44 PM Tom Lane <tgl@sss.pgh.pa.us> wrote:
> Hmm ... +1 for progress messages in the log, but I'm suspicious about
> the complexity-and-fragility-versus-value tradeoff for the other thing.

All right, so it's nice to hear that nobody so far is opposed to the
log-based solution, and I think it's sensible to think about building
that one first and doing anything else later.

But, if we did want to invent something to allow monitoring via libpq
even at this early stage, how would we make it work? Magnus pointed
out that we can hardly read pg_authid during crash recovery, which
means that accepting logins in the usual sense at that stage is not
feasible. But, what if we picked a fixed, hard-coded role name for
this? I would suggest pg_monitor, but that's already taken for
something else, so maybe pg_console or some better thing someone else
can suggest. Without a pg_authid row, you couldn't use password, md5,
or scram authentication, unless we provided some other place to store
the verifier, like a flatfile. I'm not sure we want to go there, but
that still leaves a lot of workable authentication methods.

I think Álvaro is right to see this kind of work as an extension of
pg_isready, but the problem with pg_isready is that we don't want to
expose a lot of information to the whole Internet, or however much of
it can reach the postgres port. But with this approach, you can lock
down access via pg_hba.conf, which means that it's OK to expose
information that we don't want to make available to everyone. I think
we're still limited to exposing what can be observed from shared
memory here, because the whole idea is to have something that can be
used even before consistency is reached, so we shouldn't really be
doing anything that would look at the contents of data files. But that
still leaves a bunch of things that we could show here, the progress
of the startup process being one of them.

-- 
Robert Haas
EDB: http://www.enterprisedb.com





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
@ 2021-04-20 13:04       ` Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  0 siblings, 1 reply; 38+ messages in thread

From: Magnus Hagander @ 2021-04-20 13:04 UTC (permalink / raw)
  To: Robert Haas <robertmhaas@gmail.com>; +Cc: Tom Lane <tgl@sss.pgh.pa.us>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

On Tue, Apr 20, 2021 at 2:43 PM Robert Haas <robertmhaas@gmail.com> wrote:
>
> On Mon, Apr 19, 2021 at 8:44 PM Tom Lane <tgl@sss.pgh.pa.us> wrote:
> > Hmm ... +1 for progress messages in the log, but I'm suspicious about
> > the complexity-and-fragility-versus-value tradeoff for the other thing.
>
> All right, so it's nice to hear that nobody so far is opposed to the
> log-based solution, and I think it's sensible to think about building
> that one first and doing anything else later.
>
> But, if we did want to invent something to allow monitoring via libpq
> even at this early stage, how would we make it work? Magnus pointed
> out that we can hardly read pg_authid during crash recovery, which
> means that accepting logins in the usual sense at that stage is not
> feasible. But, what if we picked a fixed, hard-coded role name for
> this? I would suggest pg_monitor, but that's already taken for
> something else, so maybe pg_console or some better thing someone else
> can suggest. Without a pg_authid row, you couldn't use password, md5,
> or scram authentication, unless we provided some other place to store
> the verifier, like a flatfile. I'm not sure we want to go there, but
> that still leaves a lot of workable authentication methods.

Another option would be to keep this check entirely outside the scope
of normal roles, and just listen on a port (or unix socket) during
startup which basically just replies with the current status if you
connect to it. On Unix this could also make use of peer authentication
requiring you to be the same user as postgres for example.


> I think Álvaro is right to see this kind of work as an extension of
> pg_isready, but the problem with pg_isready is that we don't want to
> expose a lot of information to the whole Internet, or however much of
> it can reach the postgres port. But with this approach, you can lock
> down access via pg_hba.conf, which means that it's OK to expose
> information that we don't want to make available to everyone. I think
> we're still limited to exposing what can be observed from shared
> memory here, because the whole idea is to have something that can be
> used even before consistency is reached, so we shouldn't really be
> doing anything that would look at the contents of data files. But that
> still leaves a bunch of things that we could show here, the progress
> of the startup process being one of them.

Yeah, I think we should definitely limit this to local access, one way
or another. Realistically using pg_hba is going to require catalog
access, isn't it? And we can't just go ignore those rows in pg_hba
that for example references role membership (as well as all those auth
methods you can't use).

-- 
 Magnus Hagander
 Me: https://www.hagander.net/
 Work: https://www.redpill-linpro.com/





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
@ 2021-04-20 15:17         ` Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  0 siblings, 1 reply; 38+ messages in thread

From: Jehan-Guillaume de Rorthais @ 2021-04-20 15:17 UTC (permalink / raw)
  To: Magnus Hagander <magnus@hagander.net>; +Cc: Robert Haas <robertmhaas@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

On Tue, 20 Apr 2021 15:04:28 +0200
Magnus Hagander <magnus@hagander.net> wrote:
[...]
> Yeah, I think we should definitely limit this to local access, one way
> or another. Realistically using pg_hba is going to require catalog
> access, isn't it? And we can't just go ignore those rows in pg_hba
> that for example references role membership (as well as all those auth
> methods you can't use).

Two another options:

1. if this is limited to local access only, outside of the log entries, the
status of the startup could be updated in the controldata file as well. This
would allows to watch it without tail-grep'ing logs using eg. pg_controldata.

2. maybe the startup process could ignore update_process_title? As far
as I understand the doc correctly, this GUC is mostly useful for backends on
Windows.

Regards,





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
@ 2021-04-20 17:32           ` Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  0 siblings, 1 reply; 38+ messages in thread

From: Magnus Hagander @ 2021-04-20 17:32 UTC (permalink / raw)
  To: Jehan-Guillaume de Rorthais <jgdr@dalibo.com>; +Cc: Robert Haas <robertmhaas@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

On Tue, Apr 20, 2021 at 5:17 PM Jehan-Guillaume de Rorthais
<jgdr@dalibo.com> wrote:
>
> On Tue, 20 Apr 2021 15:04:28 +0200
> Magnus Hagander <magnus@hagander.net> wrote:
> [...]
> > Yeah, I think we should definitely limit this to local access, one way
> > or another. Realistically using pg_hba is going to require catalog
> > access, isn't it? And we can't just go ignore those rows in pg_hba
> > that for example references role membership (as well as all those auth
> > methods you can't use).
>
> Two another options:
>
> 1. if this is limited to local access only, outside of the log entries, the
> status of the startup could be updated in the controldata file as well. This
> would allows to watch it without tail-grep'ing logs using eg. pg_controldata.

I think doing so in controldata would definitely make things
complicated for no real reason. Plus controldata has a fixed size (and
has to have), whereas something like this would probably want more
variation than that makes easy.

There could be a "startup.status" file I guess which would basically
contain the last line of what would otherwise be in the log. But if it
remains a textfile, I'm not sure what the gain is -- you'll just have
to have the dba look in more places than one to find it? It's not like
there's likely to be much other data written to the log during these
times?


> 2. maybe the startup process could ignore update_process_title? As far
> as I understand the doc correctly, this GUC is mostly useful for backends on
> Windows.

You mention Windows -- that would be one excellent reason not to go
for this particular method. Viewing the process title is much harder
on Windows, as there is actually no such thing and we fake it.

-- 
 Magnus Hagander
 Me: https://www.hagander.net/
 Work: https://www.redpill-linpro.com/





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
@ 2021-04-20 18:23             ` Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  0 siblings, 1 reply; 38+ messages in thread

From: Tom Lane @ 2021-04-20 18:23 UTC (permalink / raw)
  To: Magnus Hagander <magnus@hagander.net>; +Cc: Jehan-Guillaume de Rorthais <jgdr@dalibo.com>; Robert Haas <robertmhaas@gmail.com>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

Magnus Hagander <magnus@hagander.net> writes:
> On Tue, Apr 20, 2021 at 5:17 PM Jehan-Guillaume de Rorthais
> <jgdr@dalibo.com> wrote:
>> Two another options:
>> 1. if this is limited to local access only, outside of the log entries, the
>> status of the startup could be updated in the controldata file as well. This
>> would allows to watch it without tail-grep'ing logs using eg. pg_controldata.

> I think doing so in controldata would definitely make things
> complicated for no real reason. Plus controldata has a fixed size (and
> has to have), whereas something like this would probably want more
> variation than that makes easy.

Also, given that pg_control is as critical a bit of data as we have,
we really don't want to be writing it more often than we absolutely
have to.

> There could be a "startup.status" file I guess which would basically
> contain the last line of what would otherwise be in the log. But if it
> remains a textfile, I'm not sure what the gain is -- you'll just have
> to have the dba look in more places than one to find it? It's not like
> there's likely to be much other data written to the log during these
> times?

Yeah, once you are talking about dumping stuff in a file, it's not
clear how that's better than progress-messages-in-the-log.  People
already have a lot of tooling for looking at the postmaster log.

I think the point of Robert's other proposal is to allow remote
checks of the restart's progress, so local files aren't much of
a substitute anyway.

			regards, tom lane





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
@ 2021-04-20 18:51               ` Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  0 siblings, 1 reply; 38+ messages in thread

From: Stephen Frost @ 2021-04-20 18:51 UTC (permalink / raw)
  To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: Magnus Hagander <magnus@hagander.net>; Jehan-Guillaume de Rorthais <jgdr@dalibo.com>; Robert Haas <robertmhaas@gmail.com>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

Greetings,

* Tom Lane (tgl@sss.pgh.pa.us) wrote:
> Magnus Hagander <magnus@hagander.net> writes:
> > On Tue, Apr 20, 2021 at 5:17 PM Jehan-Guillaume de Rorthais
> > <jgdr@dalibo.com> wrote:
> >> Two another options:
> >> 1. if this is limited to local access only, outside of the log entries, the
> >> status of the startup could be updated in the controldata file as well. This
> >> would allows to watch it without tail-grep'ing logs using eg. pg_controldata.
> 
> > I think doing so in controldata would definitely make things
> > complicated for no real reason. Plus controldata has a fixed size (and
> > has to have), whereas something like this would probably want more
> > variation than that makes easy.
> 
> Also, given that pg_control is as critical a bit of data as we have,
> we really don't want to be writing it more often than we absolutely
> have to.

Yeah, don't think pg_control fiddling is what we want.  I do agree with
improving the logging situation around here, certainly.

> > There could be a "startup.status" file I guess which would basically
> > contain the last line of what would otherwise be in the log. But if it
> > remains a textfile, I'm not sure what the gain is -- you'll just have
> > to have the dba look in more places than one to find it? It's not like
> > there's likely to be much other data written to the log during these
> > times?
> 
> Yeah, once you are talking about dumping stuff in a file, it's not
> clear how that's better than progress-messages-in-the-log.  People
> already have a lot of tooling for looking at the postmaster log.

Agreed.

> I think the point of Robert's other proposal is to allow remote
> checks of the restart's progress, so local files aren't much of
> a substitute anyway.

Yeah, being able to pick up on this remotely seems like it'd be quite
nice.  I'm not really thrilled with the idea, but the best I've got
offhand for this would be a new role that's "pg_recovery_login" where an
admin can GRANT that role to the roles they'd like to be able to use to
login during the recovery process and then, for those roles, we write
out flat files to allow authentication without access to pg_authid,
whenever their password or such changes.  It's certainly a bit grotty
but I do think it'd work.  I definitely don't want to go back to having
all of pg_authid written as a flat file and I'd rather that existing
tools and libraries work with this (meaning using the same port and
speaking the PG protocol and such) rather than inventing some new thing
that listens on some other port, etc.

On the fence about tying this to 'pg_monitor' instead of using a new
predefined role.  Either way, I would definitely prefer to see the admin
have to create a role and then GRANT the predefined role to that role.
I really dislike the idea of having predefined roles that can be used to
directly log into the database.

Thanks,

Stephen

Attachments:

  signature.asc (application/pgp-signature, 818B) download

^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
@ 2021-04-20 18:56                 ` Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 19:04                   ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  0 siblings, 2 replies; 38+ messages in thread

From: Tom Lane @ 2021-04-20 18:56 UTC (permalink / raw)
  To: Stephen Frost <sfrost@snowman.net>; +Cc: Magnus Hagander <magnus@hagander.net>; Jehan-Guillaume de Rorthais <jgdr@dalibo.com>; Robert Haas <robertmhaas@gmail.com>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

Stephen Frost <sfrost@snowman.net> writes:
> Yeah, being able to pick up on this remotely seems like it'd be quite
> nice.  I'm not really thrilled with the idea, but the best I've got
> offhand for this would be a new role that's "pg_recovery_login" where an
> admin can GRANT that role to the roles they'd like to be able to use to
> login during the recovery process and then, for those roles, we write
> out flat files to allow authentication without access to pg_authid,

We got rid of those flat files for good and sufficient reasons.  I really
really don't want to go back to having such.

I wonder though whether we really need authentication here.  pg_ping
already exposes whether the database is up, to anyone who can reach the
postmaster port at all.  Would it be so horrible if the "can't accept
connections" error message included a detail about "recovery is X%
done"?

			regards, tom lane





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
@ 2021-04-20 19:04                   ` Stephen Frost <sfrost@snowman.net>
  1 sibling, 0 replies; 38+ messages in thread

From: Stephen Frost @ 2021-04-20 19:04 UTC (permalink / raw)
  To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: Magnus Hagander <magnus@hagander.net>; Jehan-Guillaume de Rorthais <jgdr@dalibo.com>; Robert Haas <robertmhaas@gmail.com>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

Greetings,

* Tom Lane (tgl@sss.pgh.pa.us) wrote:
> Stephen Frost <sfrost@snowman.net> writes:
> > Yeah, being able to pick up on this remotely seems like it'd be quite
> > nice.  I'm not really thrilled with the idea, but the best I've got
> > offhand for this would be a new role that's "pg_recovery_login" where an
> > admin can GRANT that role to the roles they'd like to be able to use to
> > login during the recovery process and then, for those roles, we write
> > out flat files to allow authentication without access to pg_authid,
> 
> We got rid of those flat files for good and sufficient reasons.  I really
> really don't want to go back to having such.

Yeah, certainly is part of the reason that I didn't really like that
idea either.

> I wonder though whether we really need authentication here.  pg_ping
> already exposes whether the database is up, to anyone who can reach the
> postmaster port at all.  Would it be so horrible if the "can't accept
> connections" error message included a detail about "recovery is X%
> done"?

Ultimately it seems like it would depend on exactly what we are thinking
of returning there.  A simple percentage of recovery which has been
completed doesn't seem like it'd really be revealing too much
information though.

Thanks,

Stephen

Attachments:

  signature.asc (application/pgp-signature, 818B) download

^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
@ 2021-04-20 20:36                   ` Andres Freund <andres@anarazel.de>
  2021-04-21 18:36                     ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  1 sibling, 1 reply; 38+ messages in thread

From: Andres Freund @ 2021-04-20 20:36 UTC (permalink / raw)
  To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: Stephen Frost <sfrost@snowman.net>; Magnus Hagander <magnus@hagander.net>; Jehan-Guillaume de Rorthais <jgdr@dalibo.com>; Robert Haas <robertmhaas@gmail.com>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

Hi,

On 2021-04-20 14:56:58 -0400, Tom Lane wrote:
> I wonder though whether we really need authentication here.  pg_ping
> already exposes whether the database is up, to anyone who can reach the
> postmaster port at all.  Would it be so horrible if the "can't accept
> connections" error message included a detail about "recovery is X%
> done"?

Unfortunately I think something like a percentage is hard to calculate
right now.  Even just looking at crash recovery (vs replication or
PITR), we don't currently know where the WAL ends without reading all
the WAL. The easiest thing to return would be something in LSNs or
bytes and I suspect that we don't want to expose either unauthenticated?

I wonder if we ought to occasionally update something like
ControlFileData->minRecoveryPoint on primaries, similar to what we do on
standbys? Then we could actually calculate a percentage, and it'd have
the added advantage of allowing to detect more cases where the end of
the WAL was lost. Obviously we'd have to throttle it somehow, to avoid
adding a lot of fsyncs, but that seems doable?

Greetings,

Andres Freund





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
@ 2021-04-21 18:36                     ` Stephen Frost <sfrost@snowman.net>
  2021-04-21 18:43                       ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-21 19:36                       ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  0 siblings, 2 replies; 38+ messages in thread

From: Stephen Frost @ 2021-04-21 18:36 UTC (permalink / raw)
  To: Andres Freund <andres@anarazel.de>; +Cc: Tom Lane <tgl@sss.pgh.pa.us>; Magnus Hagander <magnus@hagander.net>; Jehan-Guillaume de Rorthais <jgdr@dalibo.com>; Robert Haas <robertmhaas@gmail.com>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

Greetings,

* Andres Freund (andres@anarazel.de) wrote:
> On 2021-04-20 14:56:58 -0400, Tom Lane wrote:
> > I wonder though whether we really need authentication here.  pg_ping
> > already exposes whether the database is up, to anyone who can reach the
> > postmaster port at all.  Would it be so horrible if the "can't accept
> > connections" error message included a detail about "recovery is X%
> > done"?
> 
> Unfortunately I think something like a percentage is hard to calculate
> right now.  Even just looking at crash recovery (vs replication or
> PITR), we don't currently know where the WAL ends without reading all
> the WAL. The easiest thing to return would be something in LSNs or
> bytes and I suspect that we don't want to expose either unauthenticated?

While it obviously wouldn't be exactly accurate, I wonder if we couldn't
just look at the WAL files we have to reply and then guess that we'll go
through about half of them before we reach the end..?  I mean, wouldn't
exactly be the first time that a percentage progress report wasn't
completely accurate. :)

> I wonder if we ought to occasionally update something like
> ControlFileData->minRecoveryPoint on primaries, similar to what we do on
> standbys? Then we could actually calculate a percentage, and it'd have
> the added advantage of allowing to detect more cases where the end of
> the WAL was lost. Obviously we'd have to throttle it somehow, to avoid
> adding a lot of fsyncs, but that seems doable?

This seems to go against Tom's concerns wrt rewriting pg_control.
Perhaps we could work through a solution to that, which would be nice,
but I'm not sure that we need the percentage to be super accurate
anyway, though, ideally, we'd work it out so that it's always increasing
and doesn't look "stuck" as long as we're actually moving forward
through the WAL.

Maybe a heuristic of 'look at the end of the WAL files, assume we'll go
through 50% of it, but only consider that to be 90%, with the last 10%
going from half-way through the WAL to the actual end of the WAL
available."

Yes, such heuristics are terrible, but they're also relatively simple
and wouldn't require tracking anything additional and would, maybe,
avoid the concern about needing to authenticate the user..

Thanks,

Stephen

Attachments:

  signature.asc (application/pgp-signature, 818B) download

^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 18:36                     ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
@ 2021-04-21 18:43                       ` Tom Lane <tgl@sss.pgh.pa.us>
  1 sibling, 0 replies; 38+ messages in thread

From: Tom Lane @ 2021-04-21 18:43 UTC (permalink / raw)
  To: Stephen Frost <sfrost@snowman.net>; +Cc: Andres Freund <andres@anarazel.de>; Magnus Hagander <magnus@hagander.net>; Jehan-Guillaume de Rorthais <jgdr@dalibo.com>; Robert Haas <robertmhaas@gmail.com>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

Stephen Frost <sfrost@snowman.net> writes:
> * Andres Freund (andres@anarazel.de) wrote:
>> On 2021-04-20 14:56:58 -0400, Tom Lane wrote:
>>> I wonder though whether we really need authentication here.  pg_ping
>>> already exposes whether the database is up, to anyone who can reach the
>>> postmaster port at all.  Would it be so horrible if the "can't accept
>>> connections" error message included a detail about "recovery is X%
>>> done"?

>> Unfortunately I think something like a percentage is hard to calculate
>> right now.

> While it obviously wouldn't be exactly accurate, I wonder if we couldn't
> just look at the WAL files we have to reply and then guess that we'll go
> through about half of them before we reach the end..?  I mean, wouldn't
> exactly be the first time that a percentage progress report wasn't
> completely accurate. :)

Or we could skip all the guessing and just print something like what
the startup process exposes in ps status, ie "currently processing
WAL file so-and-so".

			regards, tom lane





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 18:36                     ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
@ 2021-04-21 19:36                       ` Andres Freund <andres@anarazel.de>
  2021-04-21 19:51                         ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 23:09                         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  1 sibling, 2 replies; 38+ messages in thread

From: Andres Freund @ 2021-04-21 19:36 UTC (permalink / raw)
  To: Stephen Frost <sfrost@snowman.net>; +Cc: Tom Lane <tgl@sss.pgh.pa.us>; Magnus Hagander <magnus@hagander.net>; Jehan-Guillaume de Rorthais <jgdr@dalibo.com>; Robert Haas <robertmhaas@gmail.com>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

Hi,

On 2021-04-21 14:36:24 -0400, Stephen Frost wrote:
> * Andres Freund (andres@anarazel.de) wrote:
> > Unfortunately I think something like a percentage is hard to calculate
> > right now.  Even just looking at crash recovery (vs replication or
> > PITR), we don't currently know where the WAL ends without reading all
> > the WAL. The easiest thing to return would be something in LSNs or
> > bytes and I suspect that we don't want to expose either unauthenticated?
> 
> While it obviously wouldn't be exactly accurate, I wonder if we couldn't
> just look at the WAL files we have to reply and then guess that we'll go
> through about half of them before we reach the end..?  I mean, wouldn't
> exactly be the first time that a percentage progress report wasn't
> completely accurate. :)

I don't think that'd work well, due to WAL segment recycling. We rename
WAL files into place when removing them, and sometimes that can be a
*lot* of files. It's one thing for there to be a ~20% inaccuracy in
estimated amount of work, another to have misestimates on the order of
magnitudes.



> > I wonder if we ought to occasionally update something like
> > ControlFileData->minRecoveryPoint on primaries, similar to what we do on
> > standbys? Then we could actually calculate a percentage, and it'd have
> > the added advantage of allowing to detect more cases where the end of
> > the WAL was lost. Obviously we'd have to throttle it somehow, to avoid
> > adding a lot of fsyncs, but that seems doable?
> 
> This seems to go against Tom's concerns wrt rewriting pg_control.

I don't think that concern equally applies for what I am proposing
here. For one, we already have minRecoveryPoint in ControlData, and we
already use it for the purpose of determining where we need to recover
to, albeit only during crash recovery. Imo that's substantially
different from adding actual recovery progress status information to the
control file.

I also think that it'd actually be a significant reliability improvement
if we maintained an approximate minRecoveryPoint during normal running:
I've seen way too many cases where WAL files were lost / removed and
crash recovery just started up happily. Only hitting problems months
down the line. Yes, it'd obviously not bullet proof, since we'd not want
to add a significant stream of new fsyncs, but IME such WAL files
lost/removed issues tend not to be about a few hundred bytes of WAL but
many segments missing.


Greetings,

Andres Freund





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 18:36                     ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 19:36                       ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
@ 2021-04-21 19:51                         ` Stephen Frost <sfrost@snowman.net>
  2021-04-21 20:00                           ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  1 sibling, 1 reply; 38+ messages in thread

From: Stephen Frost @ 2021-04-21 19:51 UTC (permalink / raw)
  To: Andres Freund <andres@anarazel.de>; +Cc: Tom Lane <tgl@sss.pgh.pa.us>; Magnus Hagander <magnus@hagander.net>; Jehan-Guillaume de Rorthais <jgdr@dalibo.com>; Robert Haas <robertmhaas@gmail.com>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

Greetings,

* Andres Freund (andres@anarazel.de) wrote:
> On 2021-04-21 14:36:24 -0400, Stephen Frost wrote:
> > * Andres Freund (andres@anarazel.de) wrote:
> > > Unfortunately I think something like a percentage is hard to calculate
> > > right now.  Even just looking at crash recovery (vs replication or
> > > PITR), we don't currently know where the WAL ends without reading all
> > > the WAL. The easiest thing to return would be something in LSNs or
> > > bytes and I suspect that we don't want to expose either unauthenticated?
> > 
> > While it obviously wouldn't be exactly accurate, I wonder if we couldn't
> > just look at the WAL files we have to reply and then guess that we'll go
> > through about half of them before we reach the end..?  I mean, wouldn't
> > exactly be the first time that a percentage progress report wasn't
> > completely accurate. :)
> 
> I don't think that'd work well, due to WAL segment recycling. We rename
> WAL files into place when removing them, and sometimes that can be a
> *lot* of files. It's one thing for there to be a ~20% inaccuracy in
> estimated amount of work, another to have misestimates on the order of
> magnitudes.

I mean- we actively try to guess at how many WAL files we'll need during
each checkpoint and if we're doing that decently then it'd hopefully be
on about the order of half the files, as I suggested, that we'll end up
going through at any point in time.  Naturally, it'll be different if
there's a forced checkpoint or a sudden spike of activity, but I'm not
sure that it's an entirely unreasonable place to start if we're going to
be guessing at it.

> > > I wonder if we ought to occasionally update something like
> > > ControlFileData->minRecoveryPoint on primaries, similar to what we do on
> > > standbys? Then we could actually calculate a percentage, and it'd have
> > > the added advantage of allowing to detect more cases where the end of
> > > the WAL was lost. Obviously we'd have to throttle it somehow, to avoid
> > > adding a lot of fsyncs, but that seems doable?
> > 
> > This seems to go against Tom's concerns wrt rewriting pg_control.
> 
> I don't think that concern equally applies for what I am proposing
> here. For one, we already have minRecoveryPoint in ControlData, and we
> already use it for the purpose of determining where we need to recover
> to, albeit only during crash recovery. Imo that's substantially
> different from adding actual recovery progress status information to the
> control file.

I agree that it's not the same as adding actual recovery progress status
information.

> I also think that it'd actually be a significant reliability improvement
> if we maintained an approximate minRecoveryPoint during normal running:
> I've seen way too many cases where WAL files were lost / removed and
> crash recovery just started up happily. Only hitting problems months
> down the line. Yes, it'd obviously not bullet proof, since we'd not want
> to add a significant stream of new fsyncs, but IME such WAL files
> lost/removed issues tend not to be about a few hundred bytes of WAL but
> many segments missing.

I do agree that it's definitely a problem and one that I've seen as well
where we think we reach the end of recovery even though we didn't
actually.  Having a way to avoid that happening would be quite nice.  It
does seem like we have some trade-offs here to weigh, but pg_control is
indeed quite small..

Thanks,

Stephen

Attachments:

  signature.asc (application/pgp-signature, 818B) download

^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 18:36                     ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 19:36                       ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 19:51                         ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
@ 2021-04-21 20:00                           ` Andres Freund <andres@anarazel.de>
  2021-04-21 20:28                             ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  0 siblings, 1 reply; 38+ messages in thread

From: Andres Freund @ 2021-04-21 20:00 UTC (permalink / raw)
  To: Stephen Frost <sfrost@snowman.net>; +Cc: Tom Lane <tgl@sss.pgh.pa.us>; Magnus Hagander <magnus@hagander.net>; Jehan-Guillaume de Rorthais <jgdr@dalibo.com>; Robert Haas <robertmhaas@gmail.com>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

Hi,

On 2021-04-21 15:51:38 -0400, Stephen Frost wrote:
> It does seem like we have some trade-offs here to weigh, but
> pg_control is indeed quite small..

What do you mean by that? That the overhead of writing it out more
frequently wouldn't be too bad? Or that we shouldn't "unnecessarily" add
more fields to it?

Greetings,

Andres Freund





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 18:36                     ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 19:36                       ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 19:51                         ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 20:00                           ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
@ 2021-04-21 20:28                             ` Stephen Frost <sfrost@snowman.net>
  2021-04-21 20:55                               ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-21 20:58                               ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  0 siblings, 2 replies; 38+ messages in thread

From: Stephen Frost @ 2021-04-21 20:28 UTC (permalink / raw)
  To: Andres Freund <andres@anarazel.de>; +Cc: Tom Lane <tgl@sss.pgh.pa.us>; Magnus Hagander <magnus@hagander.net>; Jehan-Guillaume de Rorthais <jgdr@dalibo.com>; Robert Haas <robertmhaas@gmail.com>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

Greetings,

* Andres Freund (andres@anarazel.de) wrote:
> On 2021-04-21 15:51:38 -0400, Stephen Frost wrote:
> > It does seem like we have some trade-offs here to weigh, but
> > pg_control is indeed quite small..
> 
> What do you mean by that? That the overhead of writing it out more
> frequently wouldn't be too bad? Or that we shouldn't "unnecessarily" add
> more fields to it?

Mostly just that the added overhead in writing it out more frequently
wouldn't be too bad.  Adding fields runs the risk of crossing the
threshold where we feel that we can safely assume all of it will make it
to disk in one shot and therefore there's more reason to not add extra
fields to it, if possible.

Seems the missing bit here is "how often, and how do we make that
happen?" and then we can discuss if there's reason to be concerned that
it would be 'too frequent' or cause too much additional overhead in
terms of IO/fsyncs.

Thanks,

Stephen

Attachments:

  signature.asc (application/pgp-signature, 818B) download

^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 18:36                     ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 19:36                       ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 19:51                         ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 20:00                           ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 20:28                             ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
@ 2021-04-21 20:55                               ` Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-21 21:00                                 ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  1 sibling, 1 reply; 38+ messages in thread

From: Tom Lane @ 2021-04-21 20:55 UTC (permalink / raw)
  To: Stephen Frost <sfrost@snowman.net>; +Cc: Andres Freund <andres@anarazel.de>; Magnus Hagander <magnus@hagander.net>; Jehan-Guillaume de Rorthais <jgdr@dalibo.com>; Robert Haas <robertmhaas@gmail.com>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

Stephen Frost <sfrost@snowman.net> writes:
> * Andres Freund (andres@anarazel.de) wrote:
>> What do you mean by that? That the overhead of writing it out more
>> frequently wouldn't be too bad? Or that we shouldn't "unnecessarily" add
>> more fields to it?

> Mostly just that the added overhead in writing it out more frequently
> wouldn't be too bad.

My concern about it was not at all about performance, but that every time
you write it is a new opportunity for the filesystem to lose or corrupt
the data.

			regards, tom lane





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 18:36                     ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 19:36                       ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 19:51                         ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 20:00                           ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 20:28                             ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 20:55                               ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
@ 2021-04-21 21:00                                 ` Andres Freund <andres@anarazel.de>
  2021-04-21 21:04                                   ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  0 siblings, 1 reply; 38+ messages in thread

From: Andres Freund @ 2021-04-21 21:00 UTC (permalink / raw)
  To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: Stephen Frost <sfrost@snowman.net>; Magnus Hagander <magnus@hagander.net>; Jehan-Guillaume de Rorthais <jgdr@dalibo.com>; Robert Haas <robertmhaas@gmail.com>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

Hi,

On 2021-04-21 16:55:28 -0400, Tom Lane wrote:
> My concern about it was not at all about performance, but that every time
> you write it is a new opportunity for the filesystem to lose or corrupt
> the data.

We already do, sometimes very frequent, control file updates on standbys
to update minRecoveryLSN. I don't recall reports of that causing
corruption issues. So I'd not be too concerned about that aspect?

Greetings,

Andres Freund





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 18:36                     ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 19:36                       ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 19:51                         ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 20:00                           ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 20:28                             ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 20:55                               ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-21 21:00                                 ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
@ 2021-04-21 21:04                                   ` Stephen Frost <sfrost@snowman.net>
  0 siblings, 0 replies; 38+ messages in thread

From: Stephen Frost @ 2021-04-21 21:04 UTC (permalink / raw)
  To: Andres Freund <andres@anarazel.de>; +Cc: Jehan-Guillaume de Rorthais <jgdr@dalibo.com>; Magnus Hagander <magnus@hagander.net>; Robert Haas <robertmhaas@gmail.com>; Thomas Munro <thomas.munro@gmail.com>; Tom Lane <tgl@sss.pgh.pa.us>; pgsql-hackers

Greetings,

On Wed, Apr 21, 2021 at 17:01 Andres Freund <andres@anarazel.de> wrote:

> On 2021-04-21 16:55:28 -0400, Tom Lane wrote:
> > My concern about it was not at all about performance, but that every time
> > you write it is a new opportunity for the filesystem to lose or corrupt
> > the data.
>
> We already do, sometimes very frequent, control file updates on standbys
> to update minRecoveryLSN. I don't recall reports of that causing
> corruption issues. So I'd not be too concerned about that aspect?


Or perhaps we should consider having multiple copies..?  Though I
definitely have seen missing WAL causing difficult to realize / detect
corruption more than corrupt pg_control files...

Thanks,

Stephen

>

^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 18:36                     ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 19:36                       ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 19:51                         ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 20:00                           ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 20:28                             ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
@ 2021-04-21 20:58                               ` Andres Freund <andres@anarazel.de>
  1 sibling, 0 replies; 38+ messages in thread

From: Andres Freund @ 2021-04-21 20:58 UTC (permalink / raw)
  To: Stephen Frost <sfrost@snowman.net>; +Cc: Tom Lane <tgl@sss.pgh.pa.us>; Magnus Hagander <magnus@hagander.net>; Jehan-Guillaume de Rorthais <jgdr@dalibo.com>; Robert Haas <robertmhaas@gmail.com>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

Hi,

On 2021-04-21 16:28:26 -0400, Stephen Frost wrote:
> * Andres Freund (andres@anarazel.de) wrote:
> > On 2021-04-21 15:51:38 -0400, Stephen Frost wrote:
> > > It does seem like we have some trade-offs here to weigh, but
> > > pg_control is indeed quite small..
> > 
> > What do you mean by that? That the overhead of writing it out more
> > frequently wouldn't be too bad? Or that we shouldn't "unnecessarily" add
> > more fields to it?
> 
> Mostly just that the added overhead in writing it out more frequently
> wouldn't be too bad.
>
> Seems the missing bit here is "how often, and how do we make that
> happen?" and then we can discuss if there's reason to be concerned that
> it would be 'too frequent' or cause too much additional overhead in
> terms of IO/fsyncs.

The number of writes and the number of fsyncs of the control file
wouldn't necessarily have to be the same. We could e.g. update the file
once per segment, but only fsync it at a lower cadence. We already rely
on handling writes-without-fsync of the control file (which is trivial
due to the <= 512 byte limit).

Another interesting question is where we'd do the update from. It seems
like it ought to be some background process:

I can see doing it in the checkpointer - but there's a few phases that
can take a while (e.g. sync) where currently don't call something like
CheckpointWriteDelay() on a regular basis.

I also can see doing it in bgwriter - none of the work it does should
take all that long, and minor increases in latency ought not to have
much of an impact.

Wal writer seems less suitable, some workloads are sensitive to it not
getting around doing what it ought to do.


> Adding fields runs the risk of crossing the
> threshold where we feel that we can safely assume all of it will make it
> to disk in one shot and therefore there's more reason to not add extra
> fields to it, if possible.

Yea, we really should stay below 512 bytes (sector size). We're at 296
right now, with 20 bytes lost to padding. If we got close to the limit
we could easily move some of the contents out of pg_control - we
e.g. don't need to write out all the compile time values all the time,
they could live in a file similar to PG_VERSION instead.  So I'm not too
concerned right now.  But we also don't need to add anything, given that
we already have minRecoveryPoint.

Greetings,

Andres Freund





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 18:36                     ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 19:36                       ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
@ 2021-04-21 23:09                         ` Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-06-04 14:19                           ` Re: when the startup process doesn't Nitin Jadhav <nitinjadhavpostgres@gmail.com>
  1 sibling, 1 reply; 38+ messages in thread

From: Jehan-Guillaume de Rorthais @ 2021-04-21 23:09 UTC (permalink / raw)
  To: Andres Freund <andres@anarazel.de>; +Cc: Stephen Frost <sfrost@snowman.net>; Tom Lane <tgl@sss.pgh.pa.us>; Magnus Hagander <magnus@hagander.net>; Robert Haas <robertmhaas@gmail.com>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

On Wed, 21 Apr 2021 12:36:05 -0700
Andres Freund <andres@anarazel.de> wrote:

>  [...]  
> 
> I don't think that concern equally applies for what I am proposing
> here. For one, we already have minRecoveryPoint in ControlData, and we
> already use it for the purpose of determining where we need to recover
> to, albeit only during crash recovery. Imo that's substantially
> different from adding actual recovery progress status information to the
> control file.

Just for the record, when I was talking about updating status of the startup
in the controldata, I was thinking about setting the last known LSN replayed.
Not some kind of variable string.

> 
> I also think that it'd actually be a significant reliability improvement
> if we maintained an approximate minRecoveryPoint during normal running:
> I've seen way too many cases where WAL files were lost / removed and
> crash recovery just started up happily. Only hitting problems months
> down the line. Yes, it'd obviously not bullet proof, since we'd not want
> to add a significant stream of new fsyncs, but IME such WAL files
> lost/removed issues tend not to be about a few hundred bytes of WAL but
> many segments missing.

Maybe setting this minRecoveryPoint once per segment would be enough, near
from the beginning of the WAL. At least, the recovery process would be
forced to actually replay until the very last known segment.

Regards,





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 18:36                     ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 19:36                       ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 23:09                         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
@ 2021-06-04 14:19                           ` Nitin Jadhav <nitinjadhavpostgres@gmail.com>
  2021-06-06 22:23                             ` Re: when the startup process doesn't Justin Pryzby <pryzby@telsasoft.com>
  0 siblings, 1 reply; 38+ messages in thread

From: Nitin Jadhav @ 2021-06-04 14:19 UTC (permalink / raw)
  To: Robert Haas <robertmhaas@gmail.com>; +Cc: Andres Freund <andres@anarazel.de>; Stephen Frost <sfrost@snowman.net>; Tom Lane <tgl@sss.pgh.pa.us>; Magnus Hagander <magnus@hagander.net>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

Hi,

As nobody opposed the log based approach, I thought of creating a
patch using this approach. Please find the patch attached.

Introduced the new GUC variable 'log_min_duration_startup_process'
which indicates the time period after every time period it logs the
progress of the process startup when it is set to a value (In
millisecond) greater than zero. if it is set to zero, then it logs all
available messages. If it is set to -1, then disables the feature.

> There are probably a number of reasons why this can happen, but the
> ones that seem to come up most often in my experience are
> (1) SyncDataDirectory takes a long time, (b) ResetUnloggedRelations
> takes a long time, and (c) there's a lot of WAL to apply so that takes a
> long time.

I have added the proper logs in all of the above scenarios.

Following is the sample log displayed during server startup when the
time period is set to 10ms.

2021-06-04 19:40:06.390 IST [51116] LOG:  Syncing data directory,
elapsed time: 14.165 ms,  current path: ./base/13892/16384_fsm
2021-06-04 19:40:06.399 IST [51116] LOG:  Syncing data directory
completed after 22.661 ms
2021-06-04 19:40:06.399 IST [51116] LOG:  database system was not
properly shut down; automatic recovery in progress
2021-06-04 19:40:06.401 IST [51116] LOG:  Resetting unlogged relations
completed after 0.219 ms
2021-06-04 19:40:06.401 IST [51116] LOG:  redo starts at 0/4728B88
2021-06-04 19:40:06.411 IST [51116] LOG:  Performing crash recovery,
elapsed time: 10.002 ms,  current LSN: 0/47AA998
2021-06-04 19:40:06.421 IST [51116] LOG:  Performing crash recovery,
elapsed time: 20.002 ms,  current LSN: 0/4838D80
2021-06-04 19:40:06.431 IST [51116] LOG:  Performing crash recovery,
elapsed time: 30.002 ms,  current LSN: 0/48DA718
2021-06-04 19:40:06.441 IST [51116] LOG:  Performing crash recovery,
elapsed time: 40.002 ms,  current LSN: 0/49791C0
.
.
.
2021-06-04 19:40:07.222 IST [51116] LOG:  Performing crash recovery,
elapsed time: 820.805 ms,  current LSN: 0/76F6F10
2021-06-04 19:40:07.227 IST [51116] LOG:  invalid record length at
0/774E758: wanted 24, got 0
2021-06-04 19:40:07.227 IST [51116] LOG:  redo done at 0/774E730
system usage: CPU: user: 0.77 s, system: 0.03 s, elapsed: 0.82 s

Kindly let me know if any changes are required.

Thanks & Regards,
Nitin Jadhav

On Thu, Apr 22, 2021 at 4:39 AM Jehan-Guillaume de Rorthais
<jgdr@dalibo.com> wrote:
>
> On Wed, 21 Apr 2021 12:36:05 -0700
> Andres Freund <andres@anarazel.de> wrote:
>
> >  [...]
> >
> > I don't think that concern equally applies for what I am proposing
> > here. For one, we already have minRecoveryPoint in ControlData, and we
> > already use it for the purpose of determining where we need to recover
> > to, albeit only during crash recovery. Imo that's substantially
> > different from adding actual recovery progress status information to the
> > control file.
>
> Just for the record, when I was talking about updating status of the startup
> in the controldata, I was thinking about setting the last known LSN replayed.
> Not some kind of variable string.
>
> >
> > I also think that it'd actually be a significant reliability improvement
> > if we maintained an approximate minRecoveryPoint during normal running:
> > I've seen way too many cases where WAL files were lost / removed and
> > crash recovery just started up happily. Only hitting problems months
> > down the line. Yes, it'd obviously not bullet proof, since we'd not want
> > to add a significant stream of new fsyncs, but IME such WAL files
> > lost/removed issues tend not to be about a few hundred bytes of WAL but
> > many segments missing.
>
> Maybe setting this minRecoveryPoint once per segment would be enough, near
> from the beginning of the WAL. At least, the recovery process would be
> forced to actually replay until the very last known segment.
>
> Regards,
>
>

Attachments:

v1_startup_process_progress.patch (application/octet-stream, 8.8K) download diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c index 441a912..529116f 100644 --- a/src/backend/access/transam/xlog.c +++ b/src/backend/access/transam/xlog.c @@ -397,6 +397,18 @@ static bool doRequestWalReceiverReply; */ static XLogRecPtr RedoStartLSN = InvalidXLogRecPtr; +/* + * It stores the start timestamp of the operations that occur during process + * startup. + */ +static TimestampTz operationStartTimestamp; + +/* + * It stores the timestamp of the last log that happened during the logging + * of the process startup progress. + */ +static TimestampTz operationLastLogTimestamp; + /*---------- * Shared-memory data structures for XLOG control * @@ -7323,6 +7335,8 @@ StartupXLOG(void) (errmsg("redo starts at %X/%X", LSN_FORMAT_ARGS(ReadRecPtr)))); + SetCurrentOperationStartTimestamp(); + /* * main redo apply loop */ @@ -7330,6 +7344,8 @@ StartupXLOG(void) { bool switchedTLI = false; + log_startup_process_progress("Performing crash recovery", (void *) EndRecPtr, false); + #ifdef WAL_DEBUG if (XLOG_DEBUG || (rmid == RM_XACT_ID && trace_recovery_messages <= DEBUG2) || @@ -12929,3 +12945,107 @@ XLogRequestWalReceiverReply(void) { doRequestWalReceiverReply = true; } + +/* + * GetCurrentOperationStartTimestamp + * Fetches the start timestamp of the current operation. + */ +TimestampTz +GetCurrentOperationStartTimestamp(void) +{ + return operationStartTimestamp; +} + +/* + * GetCurrentOperationLastLogTimestamp + * Fetches the timestamp of the last log written for the current + * operation. + */ +TimestampTz +GetCurrentOperationLastLogTimestamp(void) +{ + return operationLastLogTimestamp; +} + +/* + * SetCurrentOperationStartTimestamp + * Sets the start timestamp of the current operation. + */ +void +SetCurrentOperationStartTimestamp(void) +{ + operationStartTimestamp = GetCurrentTimestamp(); + operationLastLogTimestamp = GetCurrentTimestamp(); +} + +/* + * SetCurrentOperationLastLogTimestamp + * Sets the current log timestamp so that this value can be used to + * compare for the minimum duration of the logging process. + */ +void +SetCurrentOperationLastLogTimestamp(void) +{ + operationLastLogTimestamp = GetCurrentTimestamp(); +} + +/* + * log_startup_process_progress + * Logs the progress of the opeartions occur during startup of the + * process. + */ +void +log_startup_process_progress(char *operation, void *data, bool is_complete) +{ + long secs; + int usecs; + int msecs; + bool exceeded_duration; + + if (log_min_duration_startup_process < 0) + return; + + if (is_complete) + { + TimestampDifference(GetCurrentOperationStartTimestamp(), + GetCurrentTimestamp(), + &secs, &usecs); + msecs = usecs / 1000; + + ereport(LOG,(errmsg("%s completed after %ld.%03d ms", + operation, secs * 1000 + msecs, + usecs % 1000), + errhidestmt(true))); + + return; + } + + TimestampDifference(GetCurrentOperationLastLogTimestamp(), + GetCurrentTimestamp(), + &secs, &usecs); + msecs = usecs / 1000; + msecs = secs * 1000 + msecs; + + exceeded_duration = (log_min_duration_startup_process > 0 && + (msecs >= log_min_duration_startup_process)); + + if (exceeded_duration) + { + SetCurrentOperationLastLogTimestamp(); + TimestampDifference(GetCurrentOperationStartTimestamp(), + GetCurrentTimestamp(), + &secs, &usecs); + msecs = usecs / 1000; + + if (strcmp(operation, "Performing crash recovery") == 0) + ereport(LOG,(errmsg("%s, elapsed time: %ld.%03d ms, current LSN: %X/%X", + operation, secs * 1000 + msecs, + usecs % 1000, LSN_FORMAT_ARGS((XLogRecPtr) data)), + errhidestmt(true))); + else + ereport(LOG,(errmsg("%s, elapsed time: %ld.%03d ms, current path: %s", + operation, secs * 1000 + msecs, + usecs % 1000, (char *) data), + errhidestmt(true))); + } +} diff --git a/src/backend/storage/file/fd.c b/src/backend/storage/file/fd.c index e8cd7ef..2a8d535 100644 --- a/src/backend/storage/file/fd.c +++ b/src/backend/storage/file/fd.c @@ -3337,6 +3337,7 @@ SyncDataDirectory(void) if (!enableFsync) return; + SetCurrentOperationStartTimestamp(); /* * If pg_wal is a symlink, we'll need to recurse into it separately, * because the first walkdir below will ignore it. @@ -3386,6 +3387,7 @@ SyncDataDirectory(void) continue; snprintf(path, MAXPGPATH, "pg_tblspc/%s", de->d_name); + log_startup_process_progress("Syncing data directory", path, false); do_syncfs(path); } FreeDir(dir); @@ -3421,6 +3423,7 @@ SyncDataDirectory(void) if (xlog_is_symlink) walkdir("pg_wal", datadir_fsync_fname, false, LOG); walkdir("pg_tblspc", datadir_fsync_fname, true, LOG); + log_startup_process_progress("Syncing data directory", NULL, true); } /* @@ -3460,6 +3463,7 @@ walkdir(const char *path, continue; snprintf(subpath, sizeof(subpath), "%s/%s", path, de->d_name); + log_startup_process_progress("Syncing data directory", subpath, false); switch (get_dirent_type(subpath, de, process_symlinks, elevel)) { diff --git a/src/backend/storage/file/reinit.c b/src/backend/storage/file/reinit.c index 40c758d..ce1f46f 100644 --- a/src/backend/storage/file/reinit.c +++ b/src/backend/storage/file/reinit.c @@ -51,6 +51,8 @@ ResetUnloggedRelations(int op) MemoryContext tmpctx, oldctx; + SetCurrentOperationStartTimestamp(); + /* Log it. */ elog(DEBUG1, "resetting unlogged relations: cleanup %d init %d", (op & UNLOGGED_RELATION_CLEANUP) != 0, @@ -88,6 +90,7 @@ ResetUnloggedRelations(int op) FreeDir(spc_dir); + log_startup_process_progress("Resetting unlogged relations", NULL, true); /* * Restore memory context. */ @@ -136,6 +139,8 @@ ResetUnloggedRelationsInTablespaceDir(const char *tsdirname, int op) snprintf(dbspace_path, sizeof(dbspace_path), "%s/%s", tsdirname, de->d_name); + log_startup_process_progress("Resetting unlogged relations", + dbspace_path, false); ResetUnloggedRelationsInDbspaceDir(dbspace_path, op); } diff --git a/src/backend/utils/misc/guc.c b/src/backend/utils/misc/guc.c index 87bc688..7fa6684 100644 --- a/src/backend/utils/misc/guc.c +++ b/src/backend/utils/misc/guc.c @@ -663,6 +663,8 @@ static char *recovery_target_lsn_string; /* should be static, but commands/variable.c needs to get at this */ char *role_string; +/* Used to log the progress of process startup */ +int log_min_duration_startup_process = -1; /* * Displayable names for context types (enum GucContext) @@ -3539,6 +3541,18 @@ static struct config_int ConfigureNamesInt[] = check_client_connection_check_interval, NULL, NULL }, + { + {"log_min_duration_startup_process", PGC_SUSET, LOGGING_WHEN, + gettext_noop("Sets the minimum time duration after every time duration " + "the progress of the process startup will be logged."), + gettext_noop("Zero prints all messages. -1 turns this feature off."), + GUC_UNIT_MS + }, + &log_min_duration_startup_process, + -1, -1, INT_MAX, + NULL, NULL, NULL + }, + /* End-of-list marker */ { {NULL, 0, 0, NULL, NULL}, NULL, 0, 0, 0, NULL, NULL, NULL diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample index ddbb6dc..545e7ba 100644 --- a/src/backend/utils/misc/postgresql.conf.sample +++ b/src/backend/utils/misc/postgresql.conf.sample @@ -521,6 +521,10 @@ # are logged regardless of their duration; 1.0 logs all # statements from all transactions, 0.0 never logs +#log_min_duration_startup_process = -1 # -1 is disabled, 0 logs all available + # messages during server startup, > 0 indicates the time + # duration after every time duration it logs the progress. + # - What to Log - #debug_print_parse = off diff --git a/src/include/access/xlog.h b/src/include/access/xlog.h index 77187c1..a84082a 100644 --- a/src/include/access/xlog.h +++ b/src/include/access/xlog.h @@ -391,6 +391,13 @@ extern void do_pg_abort_backup(int code, Datum arg); extern void register_persistent_abort_backup_handler(void); extern SessionBackupState get_backup_status(void); +extern TimestampTz GetCurrentOperationStartTimestamp(void); +extern TimestampTz GetCurrentOperationLastLogTimestamp(void); +extern void SetCurrentOperationStartTimestamp(void); +extern void SetCurrentOperationLastLogTimestamp(void); +extern void log_startup_process_progress(char *operation, void *data, + bool is_complete); + /* File path names (all relative to $PGDATA) */ #define RECOVERY_SIGNAL_FILE "recovery.signal" #define STANDBY_SIGNAL_FILE "standby.signal" diff --git a/src/include/utils/guc.h b/src/include/utils/guc.h index a7c3a49..2e9658d 100644 --- a/src/include/utils/guc.h +++ b/src/include/utils/guc.h @@ -282,6 +282,8 @@ extern int tcp_user_timeout; extern bool trace_sort; #endif +extern int log_min_duration_startup_process; + /* * Functions exported by guc.c */
^ permalink raw reply [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 18:36                     ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 19:36                       ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 23:09                         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-06-04 14:19                           ` Re: when the startup process doesn't Nitin Jadhav <nitinjadhavpostgres@gmail.com>
@ 2021-06-06 22:23                             ` Justin Pryzby <pryzby@telsasoft.com>
  2021-06-07 13:21                               ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  0 siblings, 1 reply; 38+ messages in thread

From: Justin Pryzby @ 2021-06-06 22:23 UTC (permalink / raw)
  To: Nitin Jadhav <nitinjadhavpostgres@gmail.com>; +Cc: Robert Haas <robertmhaas@gmail.com>; Andres Freund <andres@anarazel.de>; Stephen Frost <sfrost@snowman.net>; Tom Lane <tgl@sss.pgh.pa.us>; Magnus Hagander <magnus@hagander.net>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

On Fri, Jun 04, 2021 at 07:49:21PM +0530, Nitin Jadhav wrote:
> I have added the proper logs in all of the above scenarios.
> 
> Following is the sample log displayed during server startup when the
> time period is set to 10ms.
> 
> 2021-06-04 19:40:06.390 IST [51116] LOG:  Syncing data directory, elapsed time: 14.165 ms,  current path: ./base/13892/16384_fsm
> 2021-06-04 19:40:06.399 IST [51116] LOG:  Syncing data directory completed after 22.661 ms

|2021-06-04 19:40:07.222 IST [51116] LOG:  Performing crash recovery, elapsed time: 820.805 ms,  current LSN: 0/76F6F10
|2021-06-04 19:40:07.227 IST [51116] LOG:  invalid record length at 0/774E758: wanted 24, got 0
|2021-06-04 19:40:07.227 IST [51116] LOG:  redo done at 0/774E730 system usage: CPU: user: 0.77 s, system: 0.03 s, elapsed: 0.82 s

Should it show the rusage ?  It's shown at startup completion since 10a5b35a0,
so it seems strange not to show it here.

+                       log_startup_process_progress("Syncing data directory", path, false);

I think the fsync vs syncfs paths should be distinguished: "Syncing data
directory (fsync)" vs "Syncing data directory (syncfs)".

+               {"log_min_duration_startup_process", PGC_SUSET, LOGGING_WHEN,

I think it should be PGC_SIGHUP, to allow changing it during runtime.
Obviously it has no effect except during startup, but the change will be
effective if the current process crashes.
See also: https://www.postgresql.org/message-id/20210526001359.GE3676@telsasoft.com

+extern void log_startup_process_progress(char *operation, void *data,
+                                         bool is_complete);

I think this should take an enum operation, rather than using strcmp() on it
later.  The enum values might be RECOVERY_START, RECOVERY_END, rather than
having a bool is_complete.

-- 
Justin





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 18:36                     ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 19:36                       ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 23:09                         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-06-04 14:19                           ` Re: when the startup process doesn't Nitin Jadhav <nitinjadhavpostgres@gmail.com>
  2021-06-06 22:23                             ` Re: when the startup process doesn't Justin Pryzby <pryzby@telsasoft.com>
@ 2021-06-07 13:21                               ` Robert Haas <robertmhaas@gmail.com>
  2021-06-07 13:42                                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  0 siblings, 1 reply; 38+ messages in thread

From: Robert Haas @ 2021-06-07 13:21 UTC (permalink / raw)
  To: Justin Pryzby <pryzby@telsasoft.com>; +Cc: Nitin Jadhav <nitinjadhavpostgres@gmail.com>; Andres Freund <andres@anarazel.de>; Stephen Frost <sfrost@snowman.net>; Tom Lane <tgl@sss.pgh.pa.us>; Magnus Hagander <magnus@hagander.net>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

On Sun, Jun 6, 2021 at 6:23 PM Justin Pryzby <pryzby@telsasoft.com> wrote:
> Should it show the rusage ?  It's shown at startup completion since 10a5b35a0,
> so it seems strange not to show it here.

I don't know, that seems like it's going to make the messages awfully
long, and I'm not sure of what use it is to see that for every report.

I don't like the name very much. log_min_duration_startup_process
seems to have been chosen to correspond to log_min_duration_statement,
but the semantics are different. That one is a threshold, whereas this
one is an interval. Maybe something like
log_startup_progress_interval?

As far as the patch itself goes, I think that the overhead of this
approach is going to be unacceptably high. I was imagining having a
timer running in the background that fires periodically, with the
interval handler just setting a flag. Then in the foreground we just
need to check whether the flag is set. I doubt that we can get away
with a GetCurrentTimestamp() after applying every WAL record ... that
seems like it will be slow.

--
Robert Haas
EDB: http://www.enterprisedb.com





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 18:36                     ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 19:36                       ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 23:09                         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-06-04 14:19                           ` Re: when the startup process doesn't Nitin Jadhav <nitinjadhavpostgres@gmail.com>
  2021-06-06 22:23                             ` Re: when the startup process doesn't Justin Pryzby <pryzby@telsasoft.com>
  2021-06-07 13:21                               ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
@ 2021-06-07 13:42                                 ` Tom Lane <tgl@sss.pgh.pa.us>
  2021-06-09 11:39                                   ` Re: when the startup process doesn't Nitin Jadhav <nitinjadhavpostgres@gmail.com>
  0 siblings, 1 reply; 38+ messages in thread

From: Tom Lane @ 2021-06-07 13:42 UTC (permalink / raw)
  To: Robert Haas <robertmhaas@gmail.com>; +Cc: Justin Pryzby <pryzby@telsasoft.com>; Nitin Jadhav <nitinjadhavpostgres@gmail.com>; Andres Freund <andres@anarazel.de>; Stephen Frost <sfrost@snowman.net>; Magnus Hagander <magnus@hagander.net>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

Robert Haas <robertmhaas@gmail.com> writes:
> ... I doubt that we can get away
> with a GetCurrentTimestamp() after applying every WAL record ... that
> seems like it will be slow.

Yeah, that's going to be pretty awful even on machines with fast
gettimeofday, never mind ones where it isn't.

It should be possible to use utils/misc/timeout.c to manage the
interrupt, I'd think.

			regards, tom lane





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 18:36                     ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 19:36                       ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 23:09                         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-06-04 14:19                           ` Re: when the startup process doesn't Nitin Jadhav <nitinjadhavpostgres@gmail.com>
  2021-06-06 22:23                             ` Re: when the startup process doesn't Justin Pryzby <pryzby@telsasoft.com>
  2021-06-07 13:21                               ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-06-07 13:42                                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
@ 2021-06-09 11:39                                   ` Nitin Jadhav <nitinjadhavpostgres@gmail.com>
  2021-06-09 16:19                                     ` Re: when the startup process doesn't Justin Pryzby <pryzby@telsasoft.com>
  0 siblings, 1 reply; 38+ messages in thread

From: Nitin Jadhav @ 2021-06-09 11:39 UTC (permalink / raw)
  To: Tom Lane <tgl@sss.pgh.pa.us>; +Cc: Robert Haas <robertmhaas@gmail.com>; Justin Pryzby <pryzby@telsasoft.com>; Andres Freund <andres@anarazel.de>; Stephen Frost <sfrost@snowman.net>; Magnus Hagander <magnus@hagander.net>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

> Should it show the rusage ?  It's shown at startup completion since 10a5b35a0,
> so it seems strange not to show it here.

> I don't know, that seems like it's going to make the messages awfully
> long, and I'm not sure of what use it is to see that for every report.

I have not changed anything wrt this. If it is really required to
change, then I will change.

> +                       log_startup_process_progress("Syncing data directory", path, false);

> I think the fsync vs syncfs paths should be distinguished: "Syncing data
> directory (fsync)" vs "Syncing data directory (syncfs)".

Fixed.

> +               {"log_min_duration_startup_process", PGC_SUSET, LOGGING_WHEN,
>
> I think it should be PGC_SIGHUP, to allow changing it during runtime.
> Obviously it has no effect except during startup, but the change will be
> effective if the current process crashes.
> See also: https://www.postgresql.org/message-id/20210526001359.GE3676@telsasoft.com

I did not get exactly how it will change behaviour. In my
understanding, when the server restarts after a crash, it fetches the
value from the config file. So if there is any change that gets
affected. Kindly correct me if I am wrong.

> +extern void log_startup_process_progress(char *operation, void *data,
> +                                         bool is_complete);
>
> I think this should take an enum operation, rather than using strcmp() on it
> later.  The enum values might be RECOVERY_START, RECOVERY_END, rather than
> having a bool is_complete.

Fixed.

> I don't like the name very much. log_min_duration_startup_process
> seems to have been chosen to correspond to log_min_duration_statement,
> but the semantics are different. That one is a threshold, whereas this
> one is an interval. Maybe something like
> log_startup_progress_interval?

Yes. This looks more appropriate. Fixed in the attached patch.

> As far as the patch itself goes, I think that the overhead of this
> approach is going to be unacceptably high. I was imagining having a
> timer running in the background that fires periodically, with the
> interval handler just setting a flag. Then in the foreground we just
> need to check whether the flag is set. I doubt that we can get away
> with a GetCurrentTimestamp() after applying every WAL record ... that
> seems like it will be slow.

Thanks for correcting me. This approach is far better than what I had
used earlier. I have done the code changes as per your approach in the
attached patch.

Kindly let me know if any changes are required.

Thanks & Regards,
Nitin Jadhav

On Mon, Jun 7, 2021 at 7:12 PM Tom Lane <tgl@sss.pgh.pa.us> wrote:
>
> Robert Haas <robertmhaas@gmail.com> writes:
> > ... I doubt that we can get away
> > with a GetCurrentTimestamp() after applying every WAL record ... that
> > seems like it will be slow.
>
> Yeah, that's going to be pretty awful even on machines with fast
> gettimeofday, never mind ones where it isn't.
>
> It should be possible to use utils/misc/timeout.c to manage the
> interrupt, I'd think.
>
>                         regards, tom lane

Attachments:

v2_startup_process_progress.patch (application/octet-stream, 12.2K) download diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c index 441a912..43c4d0a 100644 --- a/src/backend/access/transam/xlog.c +++ b/src/backend/access/transam/xlog.c @@ -80,6 +80,7 @@ #include "utils/pg_rusage.h" #include "utils/snapmgr.h" #include "utils/timestamp.h" +#include "utils/timeout.h" extern uint32 bootstrap_data_checksum_version; @@ -397,6 +398,18 @@ static bool doRequestWalReceiverReply; */ static XLogRecPtr RedoStartLSN = InvalidXLogRecPtr; +/* + * It stores the start timestamp of the operation that occur during process + * startup. + */ +static TimestampTz operationStartTimestamp; + +/* + * It indicates whether the startup progress interval mentioned by the user is + * elapsed or not. TRUE if timeout occured. FALSE otherwise. + */ +static bool logStartupProgressTimeout; + /*---------- * Shared-memory data structures for XLOG control * @@ -7323,6 +7336,7 @@ StartupXLOG(void) (errmsg("redo starts at %X/%X", LSN_FORMAT_ARGS(ReadRecPtr)))); + InitCurrentOperation(); /* * main redo apply loop */ @@ -7330,6 +7344,8 @@ StartupXLOG(void) { bool switchedTLI = false; + LogStartupProgress(RECOVERY_START, (void *) EndRecPtr); + #ifdef WAL_DEBUG if (XLOG_DEBUG || (rmid == RM_XACT_ID && trace_recovery_messages <= DEBUG2) || @@ -7540,6 +7556,7 @@ StartupXLOG(void) /* * end of main redo apply loop */ + LogStartupProgress(RECOVERY_END, NULL); if (reachedRecoveryTarget) { @@ -12929,3 +12946,142 @@ XLogRequestWalReceiverReply(void) { doRequestWalReceiverReply = true; } + +/* + * This function gets called when the signal SIGALRM is raised for the interval + * set for logging the progress of startup. + */ +void +LogStartupProgressTimeoutHandler(void) +{ + logStartupProgressTimeout = true; +} + +/* + * Sets the start timestamp of the current operation and also enables the + * timeout for logging the progress of startup. + */ +void +InitCurrentOperation(void) +{ + operationStartTimestamp = GetCurrentTimestamp(); + enable_timeout_after(LOG_STARTUP_PROGRESS_TIMEOUT, log_startup_progress_interval); +} + +/* + * Fetches the start timestamp of the current operation. + */ +TimestampTz +GetCurrentOperationStartTimestamp(void) +{ + return operationStartTimestamp; +} + +/* + * This function returns a string which indicates the description of the + * operation performed during process startup. + */ +static char * +get_startup_process_operation_string(StartupProcessOp operation) +{ + char *buf = NULL; + + switch (operation) + { + case SYNCFS_START: + buf = "Syncing data directory (syncfs)"; + break; + case FSYNC_START: + buf = "Syncing data directory (fsync)"; + break; + case RECOVERY_START: + buf = "Performing crash recovery"; + break; + case RESET_UNLOGGED_REL_START: + buf = "Resetting unlogged relations"; + break; + case SYNCFS_END: + buf = "Data directory sync (syncfs) complete"; + break; + case FSYNC_END: + buf = "Data directory sync (fsync) complete"; + break; + case RECOVERY_END: + break; + case RESET_UNLOGGED_REL_END: + buf = "Unlogged relations reset"; + break; + } + return buf; +} + +/* + * Logs the progress of the operations performed during process startup. + */ +void +LogStartupProgress(StartupProcessOp operation, void *data) +{ + long secs; + int usecs; + int msecs; + + /* If the feature is disabled, then no need to proceed further. */ + if (log_startup_progress_interval < 0) + return; + + /* + * This block gets executed when the current opearion is completed. It logs + * the details of the operation and also disables the timeout. Note that in + * case of recovery, it does not log the details since enough information is + * already logged. + */ + if (operation >= SYNCFS_END) + { + if (operation != RECOVERY_END) + { + TimestampDifference(GetCurrentOperationStartTimestamp(), + GetCurrentTimestamp(), + &secs, &usecs); + msecs = usecs / 1000; + + ereport(LOG,(errmsg("%s after %ld.%03d ms", + get_startup_process_operation_string(operation), + secs * 1000 + msecs, usecs % 1000), + errhidestmt(true))); + } + + disable_timeout(LOG_STARTUP_PROGRESS_TIMEOUT, false); + return; + } + + /* If the timeout has not occured, then no need to log the details. */ + if (!logStartupProgressTimeout) + return; + + /* Timeout has occured. Log the necessary details. */ + TimestampDifference(GetCurrentOperationStartTimestamp(), + GetCurrentTimestamp(), + &secs, &usecs); + msecs = usecs / 1000; + + if (operation == RECOVERY_START) + ereport(LOG,(errmsg("%s, elapsed time: %ld.%03d ms, current LSN: %X/%X", + get_startup_process_operation_string(operation), + secs * 1000 + msecs, usecs % 1000, + LSN_FORMAT_ARGS((XLogRecPtr) data)), + errhidestmt(true))); + else + ereport(LOG,(errmsg("%s, elapsed time: %ld.%03d ms, current path: %s", + get_startup_process_operation_string(operation), + secs * 1000 + msecs, usecs % 1000, (char *) data), + errhidestmt(true))); + + /* + * Set the flag to false and enable the timeout to log the progress if any in + * the future. + */ + logStartupProgressTimeout = false; + enable_timeout_after(LOG_STARTUP_PROGRESS_TIMEOUT, log_startup_progress_interval); + + return; +} diff --git a/src/backend/postmaster/startup.c b/src/backend/postmaster/startup.c index 69077bd..08c271c 100644 --- a/src/backend/postmaster/startup.c +++ b/src/backend/postmaster/startup.c @@ -232,6 +232,7 @@ StartupProcessMain(void) RegisterTimeout(STANDBY_DEADLOCK_TIMEOUT, StandbyDeadLockHandler); RegisterTimeout(STANDBY_TIMEOUT, StandbyTimeoutHandler); RegisterTimeout(STANDBY_LOCK_TIMEOUT, StandbyLockTimeoutHandler); + RegisterTimeout(LOG_STARTUP_PROGRESS_TIMEOUT, LogStartupProgressTimeoutHandler); /* * Unblock signals (they were blocked when the postmaster forked us) diff --git a/src/backend/storage/file/fd.c b/src/backend/storage/file/fd.c index e8cd7ef..9df893d 100644 --- a/src/backend/storage/file/fd.c +++ b/src/backend/storage/file/fd.c @@ -100,6 +100,7 @@ #include "storage/ipc.h" #include "utils/guc.h" #include "utils/resowner_private.h" +#include "utils/timeout.h" /* Define PG_FLUSH_DATA_WORKS if we have an implementation for pg_flush_data */ #if defined(HAVE_SYNC_FILE_RANGE) @@ -3366,6 +3367,7 @@ SyncDataDirectory(void) DIR *dir; struct dirent *de; + InitCurrentOperation(); /* * On Linux, we don't have to open every single file one by one. We * can use syncfs() to sync whole filesystems. We only expect @@ -3386,16 +3388,20 @@ SyncDataDirectory(void) continue; snprintf(path, MAXPGPATH, "pg_tblspc/%s", de->d_name); + LogStartupProgress(SYNCFS_START, path); do_syncfs(path); } FreeDir(dir); /* If pg_wal is a symlink, process that too. */ if (xlog_is_symlink) do_syncfs("pg_wal"); + + LogStartupProgress(SYNCFS_END, NULL); return; } #endif /* !HAVE_SYNCFS */ + InitCurrentOperation(); /* * If possible, hint to the kernel that we're soon going to fsync the data * directory and its contents. Errors in this step are even less @@ -3421,6 +3427,7 @@ SyncDataDirectory(void) if (xlog_is_symlink) walkdir("pg_wal", datadir_fsync_fname, false, LOG); walkdir("pg_tblspc", datadir_fsync_fname, true, LOG); + LogStartupProgress(FSYNC_END, NULL); } /* @@ -3454,6 +3461,7 @@ walkdir(const char *path, char subpath[MAXPGPATH * 2]; CHECK_FOR_INTERRUPTS(); + LogStartupProgress(FSYNC_START, path); if (strcmp(de->d_name, ".") == 0 || strcmp(de->d_name, "..") == 0) diff --git a/src/backend/storage/file/reinit.c b/src/backend/storage/file/reinit.c index 40c758d..1de34b5 100644 --- a/src/backend/storage/file/reinit.c +++ b/src/backend/storage/file/reinit.c @@ -22,6 +22,8 @@ #include "storage/reinit.h" #include "utils/hsearch.h" #include "utils/memutils.h" +#include "access/xlog.h" +#include "utils/timeout.h" static void ResetUnloggedRelationsInTablespaceDir(const char *tsdirname, int op); @@ -75,6 +77,7 @@ ResetUnloggedRelations(int op) */ spc_dir = AllocateDir("pg_tblspc"); + InitCurrentOperation(); while ((spc_de = ReadDir(spc_dir, "pg_tblspc")) != NULL) { if (strcmp(spc_de->d_name, ".") == 0 || @@ -83,9 +86,11 @@ ResetUnloggedRelations(int op) snprintf(temp_path, sizeof(temp_path), "pg_tblspc/%s/%s", spc_de->d_name, TABLESPACE_VERSION_DIRECTORY); + LogStartupProgress(RESET_UNLOGGED_REL_START, temp_path); ResetUnloggedRelationsInTablespaceDir(temp_path, op); } + LogStartupProgress(RESET_UNLOGGED_REL_END, NULL); FreeDir(spc_dir); /* diff --git a/src/backend/utils/misc/guc.c b/src/backend/utils/misc/guc.c index 87bc688..4039713 100644 --- a/src/backend/utils/misc/guc.c +++ b/src/backend/utils/misc/guc.c @@ -663,6 +663,9 @@ static char *recovery_target_lsn_string; /* should be static, but commands/variable.c needs to get at this */ char *role_string; +/* Used to log the progress of process startup */ +int log_startup_progress_interval = -1; + /* * Displayable names for context types (enum GucContext) @@ -3539,6 +3542,18 @@ static struct config_int ConfigureNamesInt[] = check_client_connection_check_interval, NULL, NULL }, + { + {"log_startup_progress_interval", PGC_SUSET, LOGGING_WHEN, + gettext_noop("Sets the time interval between each progress update " + "of the process startup."), + gettext_noop("Zero logs all messages. -1 turns this feature off."), + GUC_UNIT_MS + }, + &log_startup_progress_interval, + -1, -1, INT_MAX, + NULL, NULL, NULL + }, + /* End-of-list marker */ { {NULL, 0, 0, NULL, NULL}, NULL, 0, 0, 0, NULL, NULL, NULL diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample index ddbb6dc..6c2da80 100644 --- a/src/backend/utils/misc/postgresql.conf.sample +++ b/src/backend/utils/misc/postgresql.conf.sample @@ -521,6 +521,12 @@ # are logged regardless of their duration; 1.0 logs all # statements from all transactions, 0.0 never logs +#log_startup_progress_interval = -1 # Sets the time interval between each + # progress update of the process startup. + # -1 disables the feature, zero logs all + # messages, > 0 indicates the interval in + # milliseconds. + # - What to Log - #debug_print_parse = off diff --git a/src/include/access/xlog.h b/src/include/access/xlog.h index 77187c1..bb37a4d 100644 --- a/src/include/access/xlog.h +++ b/src/include/access/xlog.h @@ -287,6 +287,21 @@ typedef enum WALAvailability WALAVAIL_REMOVED /* WAL segment has been removed */ } WALAvailability; +/* + * Codes of the operations performed during process startup + */ +typedef enum StartupProcessOp +{ + SYNCFS_START, + FSYNC_START, + RECOVERY_START, + RESET_UNLOGGED_REL_START, + SYNCFS_END, + FSYNC_END, + RECOVERY_END, + RESET_UNLOGGED_REL_END, +} StartupProcessOp; + struct XLogRecData; extern XLogRecPtr XLogInsertRecord(struct XLogRecData *rdata, @@ -391,6 +406,11 @@ extern void do_pg_abort_backup(int code, Datum arg); extern void register_persistent_abort_backup_handler(void); extern SessionBackupState get_backup_status(void); +extern TimestampTz GetCurrentOperationStartTimestamp(void); +extern void InitCurrentOperation(void); +extern void LogStartupProgress(StartupProcessOp operation, void *data); +extern void LogStartupProgressTimeoutHandler(void); + /* File path names (all relative to $PGDATA) */ #define RECOVERY_SIGNAL_FILE "recovery.signal" #define STANDBY_SIGNAL_FILE "standby.signal" diff --git a/src/include/utils/guc.h b/src/include/utils/guc.h index a7c3a49..7c12632 100644 --- a/src/include/utils/guc.h +++ b/src/include/utils/guc.h @@ -282,6 +282,8 @@ extern int tcp_user_timeout; extern bool trace_sort; #endif +extern int log_startup_progress_interval; + /* * Functions exported by guc.c */ diff --git a/src/include/utils/timeout.h b/src/include/utils/timeout.h index 93e6a69..ef892dd 100644 --- a/src/include/utils/timeout.h +++ b/src/include/utils/timeout.h @@ -33,6 +33,7 @@ typedef enum TimeoutId IDLE_IN_TRANSACTION_SESSION_TIMEOUT, IDLE_SESSION_TIMEOUT, CLIENT_CONNECTION_CHECK_TIMEOUT, + LOG_STARTUP_PROGRESS_TIMEOUT, /* First user-definable timeout reason */ USER_TIMEOUT, /* Maximum number of timeout reasons */
^ permalink raw reply [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 18:36                     ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 19:36                       ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 23:09                         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-06-04 14:19                           ` Re: when the startup process doesn't Nitin Jadhav <nitinjadhavpostgres@gmail.com>
  2021-06-06 22:23                             ` Re: when the startup process doesn't Justin Pryzby <pryzby@telsasoft.com>
  2021-06-07 13:21                               ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-06-07 13:42                                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-06-09 11:39                                   ` Re: when the startup process doesn't Nitin Jadhav <nitinjadhavpostgres@gmail.com>
@ 2021-06-09 16:19                                     ` Justin Pryzby <pryzby@telsasoft.com>
  2021-06-10 09:49                                       ` Re: when the startup process doesn't Nitin Jadhav <nitinjadhavpostgres@gmail.com>
  0 siblings, 1 reply; 38+ messages in thread

From: Justin Pryzby @ 2021-06-09 16:19 UTC (permalink / raw)
  To: Nitin Jadhav <nitinjadhavpostgres@gmail.com>; +Cc: Tom Lane <tgl@sss.pgh.pa.us>; Robert Haas <robertmhaas@gmail.com>; Andres Freund <andres@anarazel.de>; Stephen Frost <sfrost@snowman.net>; Magnus Hagander <magnus@hagander.net>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

On Wed, Jun 09, 2021 at 05:09:54PM +0530, Nitin Jadhav wrote:
> > +               {"log_min_duration_startup_process", PGC_SUSET, LOGGING_WHEN,
> >
> > I think it should be PGC_SIGHUP, to allow changing it during runtime.
> > Obviously it has no effect except during startup, but the change will be
> > effective if the current process crashes.
> > See also: https://www.postgresql.org/message-id/20210526001359.GE3676@telsasoft.com
> 
> I did not get exactly how it will change behaviour. In my
> understanding, when the server restarts after a crash, it fetches the
> value from the config file. So if there is any change that gets
> affected. Kindly correct me if I am wrong.

I don't think so.  I checked and SelectConfigFiles is called only once to read
config files and cmdline args.  And not called on restart_after_crash.

The GUC definitely isn't SUSET, since it's not useful to write in a (super)
user session SET log_min_duration_startup_process=123.

I've triple checked the behavior using a patch I submitted for Thomas' syncfs
feature.  ALTER SYSTEM recovery_init_sync_method=syncfs was not picked up when
I sent SIGABRT.  But with my patch, if I also do SELECT pg_reload_conf(), then
a future crash uses syncfs.
https://www.postgresql.org/message-id/20210526001359.GE3676@telsasoft.com

-- 
Justin





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 18:36                     ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 19:36                       ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 23:09                         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-06-04 14:19                           ` Re: when the startup process doesn't Nitin Jadhav <nitinjadhavpostgres@gmail.com>
  2021-06-06 22:23                             ` Re: when the startup process doesn't Justin Pryzby <pryzby@telsasoft.com>
  2021-06-07 13:21                               ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-06-07 13:42                                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-06-09 11:39                                   ` Re: when the startup process doesn't Nitin Jadhav <nitinjadhavpostgres@gmail.com>
  2021-06-09 16:19                                     ` Re: when the startup process doesn't Justin Pryzby <pryzby@telsasoft.com>
@ 2021-06-10 09:49                                       ` Nitin Jadhav <nitinjadhavpostgres@gmail.com>
  2021-06-10 10:01                                         ` Re: when the startup process doesn't Justin Pryzby <pryzby@telsasoft.com>
  0 siblings, 1 reply; 38+ messages in thread

From: Nitin Jadhav @ 2021-06-10 09:49 UTC (permalink / raw)
  To: Justin Pryzby <pryzby@telsasoft.com>; +Cc: Tom Lane <tgl@sss.pgh.pa.us>; Robert Haas <robertmhaas@gmail.com>; Andres Freund <andres@anarazel.de>; Stephen Frost <sfrost@snowman.net>; Magnus Hagander <magnus@hagander.net>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

> > > +               {"log_min_duration_startup_process", PGC_SUSET, LOGGING_WHEN,
> > >
> > > I think it should be PGC_SIGHUP, to allow changing it during runtime.
> > > Obviously it has no effect except during startup, but the change will be
> > > effective if the current process crashes.
> > > See also: https://www.postgresql.org/message-id/20210526001359.GE3676@telsasoft.com
> >
> > I did not get exactly how it will change behaviour. In my
> > understanding, when the server restarts after a crash, it fetches the
> > value from the config file. So if there is any change that gets
> > affected. Kindly correct me if I am wrong.

Sorry my understanding was wrong. But I'm not completely convinced
with the above description saying that the change will be effective if
the current process crashes.
AFAIK, whenever we set the GucContext less than PGC_SIGHUP (that is
either PGC_POSTMASTER or PGC_INTERNAL) then any change in the config
file will not get affected during restart after crash. If the
GucContext is greater than or equal to PGC_SIGHUP, then any change in
the config file will be changed once it receives the SIGHUP signal. So
it gets affected by a restart after a crash. So since the GucContext
set here is PGC_SUSET which is greater than PGC_SIGHUP, there is no
change in the behaviour wrt this point.

> I've triple checked the behavior using a patch I submitted for Thomas' syncfs
> feature.  ALTER SYSTEM recovery_init_sync_method=syncfs was not picked up when
> I sent SIGABRT.  But with my patch, if I also do SELECT pg_reload_conf(), then
> a future crash uses syncfs.
> https://www.postgresql.org/message-id/20210526001359.GE3676@telsasoft.com

The difference is since the behaviour is compared between
PGC_POSTMASTER and PGC_SIGHUP.

> The GUC definitely isn't SUSET, since it's not useful to write in a (super)
> user session SET log_min_duration_startup_process=123.
I agree with this. I may have to change this value as setting in a
user session is not at all useful. But I am confused between
PGC_POSTMASTER and PGC_SIGHUP. We should use PGC_SIGHUP if we would
like to allow the change during restart after a crash. Otherwise
PGC_POSTMASTER would be sufficient. Kindly share your thoughts.

Thanks & Regards,
Nitin Jadhav

On Wed, Jun 9, 2021 at 9:49 PM Justin Pryzby <pryzby@telsasoft.com> wrote:
>
> On Wed, Jun 09, 2021 at 05:09:54PM +0530, Nitin Jadhav wrote:
> > > +               {"log_min_duration_startup_process", PGC_SUSET, LOGGING_WHEN,
> > >
> > > I think it should be PGC_SIGHUP, to allow changing it during runtime.
> > > Obviously it has no effect except during startup, but the change will be
> > > effective if the current process crashes.
> > > See also: https://www.postgresql.org/message-id/20210526001359.GE3676@telsasoft.com
> >
> > I did not get exactly how it will change behaviour. In my
> > understanding, when the server restarts after a crash, it fetches the
> > value from the config file. So if there is any change that gets
> > affected. Kindly correct me if I am wrong.
>
> I don't think so.  I checked and SelectConfigFiles is called only once to read
> config files and cmdline args.  And not called on restart_after_crash.
>
> The GUC definitely isn't SUSET, since it's not useful to write in a (super)
> user session SET log_min_duration_startup_process=123.
>
> I've triple checked the behavior using a patch I submitted for Thomas' syncfs
> feature.  ALTER SYSTEM recovery_init_sync_method=syncfs was not picked up when
> I sent SIGABRT.  But with my patch, if I also do SELECT pg_reload_conf(), then
> a future crash uses syncfs.
> https://www.postgresql.org/message-id/20210526001359.GE3676@telsasoft.com
>
> --
> Justin





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 18:36                     ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 19:36                       ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 23:09                         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-06-04 14:19                           ` Re: when the startup process doesn't Nitin Jadhav <nitinjadhavpostgres@gmail.com>
  2021-06-06 22:23                             ` Re: when the startup process doesn't Justin Pryzby <pryzby@telsasoft.com>
  2021-06-07 13:21                               ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-06-07 13:42                                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-06-09 11:39                                   ` Re: when the startup process doesn't Nitin Jadhav <nitinjadhavpostgres@gmail.com>
  2021-06-09 16:19                                     ` Re: when the startup process doesn't Justin Pryzby <pryzby@telsasoft.com>
  2021-06-10 09:49                                       ` Re: when the startup process doesn't Nitin Jadhav <nitinjadhavpostgres@gmail.com>
@ 2021-06-10 10:01                                         ` Justin Pryzby <pryzby@telsasoft.com>
  2021-06-17 11:27                                           ` Re: when the startup process doesn't Nitin Jadhav <nitinjadhavpostgres@gmail.com>
  0 siblings, 1 reply; 38+ messages in thread

From: Justin Pryzby @ 2021-06-10 10:01 UTC (permalink / raw)
  To: Nitin Jadhav <nitinjadhavpostgres@gmail.com>; +Cc: Tom Lane <tgl@sss.pgh.pa.us>; Robert Haas <robertmhaas@gmail.com>; Andres Freund <andres@anarazel.de>; Stephen Frost <sfrost@snowman.net>; Magnus Hagander <magnus@hagander.net>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

On Thu, Jun 10, 2021 at 03:19:20PM +0530, Nitin Jadhav wrote:
> > > > +               {"log_min_duration_startup_process", PGC_SUSET, LOGGING_WHEN,
> > > >
> > > > I think it should be PGC_SIGHUP, to allow changing it during runtime.
> > > > Obviously it has no effect except during startup, but the change will be
> > > > effective if the current process crashes.
> > > > See also: https://www.postgresql.org/message-id/20210526001359.GE3676@telsasoft.com
> > >
> > > I did not get exactly how it will change behaviour. In my
> > > understanding, when the server restarts after a crash, it fetches the
> > > value from the config file. So if there is any change that gets
> > > affected. Kindly correct me if I am wrong.
> 
> Sorry my understanding was wrong. But I'm not completely convinced
> with the above description saying that the change will be effective if
> the current process crashes.
> AFAIK, whenever we set the GucContext less than PGC_SIGHUP (that is
> either PGC_POSTMASTER or PGC_INTERNAL) then any change in the config
> file will not get affected during restart after crash. If the
> GucContext is greater than or equal to PGC_SIGHUP, then any change in
> the config file will be changed once it receives the SIGHUP signal. So
> it gets affected by a restart after a crash. So since the GucContext
> set here is PGC_SUSET which is greater than PGC_SIGHUP, there is no
> change in the behaviour wrt this point.

Since you agreed that SUSET was wrong, and PGC_POSTMASTER doesn't allow
changing the value without restart, doesn't it follow that SIGHUP is what's
wanted ?

> > I've triple checked the behavior using a patch I submitted for Thomas' syncfs
> > feature.  ALTER SYSTEM recovery_init_sync_method=syncfs was not picked up when
> > I sent SIGABRT.  But with my patch, if I also do SELECT pg_reload_conf(), then
> > a future crash uses syncfs.
> > https://www.postgresql.org/message-id/20210526001359.GE3676@telsasoft.com
> 
> The difference is since the behaviour is compared between
> PGC_POSTMASTER and PGC_SIGHUP.
> 
> > The GUC definitely isn't SUSET, since it's not useful to write in a (super)
> > user session SET log_min_duration_startup_process=123.
> I agree with this. I may have to change this value as setting in a
> user session is not at all useful. But I am confused between
> PGC_POSTMASTER and PGC_SIGHUP. We should use PGC_SIGHUP if we would
> like to allow the change during restart after a crash. Otherwise
> PGC_POSTMASTER would be sufficient. Kindly share your thoughts.
> 
> Thanks & Regards,
> Nitin Jadhav
> 
> On Wed, Jun 9, 2021 at 9:49 PM Justin Pryzby <pryzby@telsasoft.com> wrote:
> >
> > On Wed, Jun 09, 2021 at 05:09:54PM +0530, Nitin Jadhav wrote:
> > > > +               {"log_min_duration_startup_process", PGC_SUSET, LOGGING_WHEN,
> > > >
> > > > I think it should be PGC_SIGHUP, to allow changing it during runtime.
> > > > Obviously it has no effect except during startup, but the change will be
> > > > effective if the current process crashes.
> > > > See also: https://www.postgresql.org/message-id/20210526001359.GE3676@telsasoft.com
> > >
> > > I did not get exactly how it will change behaviour. In my
> > > understanding, when the server restarts after a crash, it fetches the
> > > value from the config file. So if there is any change that gets
> > > affected. Kindly correct me if I am wrong.
> >
> > I don't think so.  I checked and SelectConfigFiles is called only once to read
> > config files and cmdline args.  And not called on restart_after_crash.
> >
> > The GUC definitely isn't SUSET, since it's not useful to write in a (super)
> > user session SET log_min_duration_startup_process=123.
> >
> > I've triple checked the behavior using a patch I submitted for Thomas' syncfs
> > feature.  ALTER SYSTEM recovery_init_sync_method=syncfs was not picked up when
> > I sent SIGABRT.  But with my patch, if I also do SELECT pg_reload_conf(), then
> > a future crash uses syncfs.
> > https://www.postgresql.org/message-id/20210526001359.GE3676@telsasoft.com





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 00:38 ` Re: when the startup process doesn't Thomas Munro <thomas.munro@gmail.com>
  2021-04-20 00:44   ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 12:43     ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 13:04       ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 15:17         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-04-20 17:32           ` Re: when the startup process doesn't Magnus Hagander <magnus@hagander.net>
  2021-04-20 18:23             ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 18:51               ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-20 18:56                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-04-20 20:36                   ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 18:36                     ` Re: when the startup process doesn't Stephen Frost <sfrost@snowman.net>
  2021-04-21 19:36                       ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
  2021-04-21 23:09                         ` Re: when the startup process doesn't Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
  2021-06-04 14:19                           ` Re: when the startup process doesn't Nitin Jadhav <nitinjadhavpostgres@gmail.com>
  2021-06-06 22:23                             ` Re: when the startup process doesn't Justin Pryzby <pryzby@telsasoft.com>
  2021-06-07 13:21                               ` Re: when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-06-07 13:42                                 ` Re: when the startup process doesn't Tom Lane <tgl@sss.pgh.pa.us>
  2021-06-09 11:39                                   ` Re: when the startup process doesn't Nitin Jadhav <nitinjadhavpostgres@gmail.com>
  2021-06-09 16:19                                     ` Re: when the startup process doesn't Justin Pryzby <pryzby@telsasoft.com>
  2021-06-10 09:49                                       ` Re: when the startup process doesn't Nitin Jadhav <nitinjadhavpostgres@gmail.com>
  2021-06-10 10:01                                         ` Re: when the startup process doesn't Justin Pryzby <pryzby@telsasoft.com>
@ 2021-06-17 11:27                                           ` Nitin Jadhav <nitinjadhavpostgres@gmail.com>
  0 siblings, 0 replies; 38+ messages in thread

From: Nitin Jadhav @ 2021-06-17 11:27 UTC (permalink / raw)
  To: Justin Pryzby <pryzby@telsasoft.com>; +Cc: Tom Lane <tgl@sss.pgh.pa.us>; Robert Haas <robertmhaas@gmail.com>; Andres Freund <andres@anarazel.de>; Stephen Frost <sfrost@snowman.net>; Magnus Hagander <magnus@hagander.net>; Thomas Munro <thomas.munro@gmail.com>; pgsql-hackers

> Since you agreed that SUSET was wrong, and PGC_POSTMASTER doesn't allow
> changing the value without restart, doesn't it follow that SIGHUP is what's
> wanted ?

Yes. I have done the changes in the attached patch.

Apart from this, I have done a few other changes to the patch. The
changes include

1. Renamed 'InitCurrentOperation' to 'InitStartupProgress()'.
2. Divided the functionality of 'LogStartupProgress()' into 2 parts.
One for logging the progress and the other to log the completion
information. The first part's function name remains as is and a new
function 'CloseStartupProgress()' added for the second part.
3. In case of any invalid operations found during logging of the
startup progress, throwing an error. This is not a concern unless the
developer makes a mistake.
4. Modified the 'StartupProcessOp' enums like 'FSYNC_START' to
'FSYNC_IN_PROGRESS' for better readability.
5. Updated the comments and some cosmetic changes.

Kindly share your comments.

Thanks & Regards,
Nitin Jadhav

On Thu, Jun 10, 2021 at 3:31 PM Justin Pryzby <pryzby@telsasoft.com> wrote:
>
> On Thu, Jun 10, 2021 at 03:19:20PM +0530, Nitin Jadhav wrote:
> > > > > +               {"log_min_duration_startup_process", PGC_SUSET, LOGGING_WHEN,
> > > > >
> > > > > I think it should be PGC_SIGHUP, to allow changing it during runtime.
> > > > > Obviously it has no effect except during startup, but the change will be
> > > > > effective if the current process crashes.
> > > > > See also: https://www.postgresql.org/message-id/20210526001359.GE3676@telsasoft.com
> > > >
> > > > I did not get exactly how it will change behaviour. In my
> > > > understanding, when the server restarts after a crash, it fetches the
> > > > value from the config file. So if there is any change that gets
> > > > affected. Kindly correct me if I am wrong.
> >
> > Sorry my understanding was wrong. But I'm not completely convinced
> > with the above description saying that the change will be effective if
> > the current process crashes.
> > AFAIK, whenever we set the GucContext less than PGC_SIGHUP (that is
> > either PGC_POSTMASTER or PGC_INTERNAL) then any change in the config
> > file will not get affected during restart after crash. If the
> > GucContext is greater than or equal to PGC_SIGHUP, then any change in
> > the config file will be changed once it receives the SIGHUP signal. So
> > it gets affected by a restart after a crash. So since the GucContext
> > set here is PGC_SUSET which is greater than PGC_SIGHUP, there is no
> > change in the behaviour wrt this point.
>
> Since you agreed that SUSET was wrong, and PGC_POSTMASTER doesn't allow
> changing the value without restart, doesn't it follow that SIGHUP is what's
> wanted ?
>
> > > I've triple checked the behavior using a patch I submitted for Thomas' syncfs
> > > feature.  ALTER SYSTEM recovery_init_sync_method=syncfs was not picked up when
> > > I sent SIGABRT.  But with my patch, if I also do SELECT pg_reload_conf(), then
> > > a future crash uses syncfs.
> > > https://www.postgresql.org/message-id/20210526001359.GE3676@telsasoft.com
> >
> > The difference is since the behaviour is compared between
> > PGC_POSTMASTER and PGC_SIGHUP.
> >
> > > The GUC definitely isn't SUSET, since it's not useful to write in a (super)
> > > user session SET log_min_duration_startup_process=123.
> > I agree with this. I may have to change this value as setting in a
> > user session is not at all useful. But I am confused between
> > PGC_POSTMASTER and PGC_SIGHUP. We should use PGC_SIGHUP if we would
> > like to allow the change during restart after a crash. Otherwise
> > PGC_POSTMASTER would be sufficient. Kindly share your thoughts.
> >
> > Thanks & Regards,
> > Nitin Jadhav
> >
> > On Wed, Jun 9, 2021 at 9:49 PM Justin Pryzby <pryzby@telsasoft.com> wrote:
> > >
> > > On Wed, Jun 09, 2021 at 05:09:54PM +0530, Nitin Jadhav wrote:
> > > > > +               {"log_min_duration_startup_process", PGC_SUSET, LOGGING_WHEN,
> > > > >
> > > > > I think it should be PGC_SIGHUP, to allow changing it during runtime.
> > > > > Obviously it has no effect except during startup, but the change will be
> > > > > effective if the current process crashes.
> > > > > See also: https://www.postgresql.org/message-id/20210526001359.GE3676@telsasoft.com
> > > >
> > > > I did not get exactly how it will change behaviour. In my
> > > > understanding, when the server restarts after a crash, it fetches the
> > > > value from the config file. So if there is any change that gets
> > > > affected. Kindly correct me if I am wrong.
> > >
> > > I don't think so.  I checked and SelectConfigFiles is called only once to read
> > > config files and cmdline args.  And not called on restart_after_crash.
> > >
> > > The GUC definitely isn't SUSET, since it's not useful to write in a (super)
> > > user session SET log_min_duration_startup_process=123.
> > >
> > > I've triple checked the behavior using a patch I submitted for Thomas' syncfs
> > > feature.  ALTER SYSTEM recovery_init_sync_method=syncfs was not picked up when
> > > I sent SIGABRT.  But with my patch, if I also do SELECT pg_reload_conf(), then
> > > a future crash uses syncfs.
> > > https://www.postgresql.org/message-id/20210526001359.GE3676@telsasoft.com

Attachments:

v3-0001-startup-process-progress.patch (application/octet-stream, 13.7K) download From d1d2f4d5df9b0dd91d8c48822f15fc3784c777bf Mon Sep 17 00:00:00 2001 From: Nitin <nitin.jadhav@enterprisedb.com> Date: Thu, 17 Jun 2021 16:32:32 +0530 Subject: [PATCH] Shows the progress of the operations performed during startup process. The interval between each progress update is configurable and it can be mentioned in milliseconds. --- src/backend/access/transam/xlog.c | 161 ++++++++++++++++++++++++++ src/backend/postmaster/startup.c | 1 + src/backend/storage/file/fd.c | 12 ++ src/backend/storage/file/reinit.c | 6 + src/backend/utils/misc/guc.c | 18 +++ src/backend/utils/misc/postgresql.conf.sample | 6 + src/include/access/xlog.h | 22 ++++ src/include/utils/guc.h | 2 + src/include/utils/timeout.h | 1 + 9 files changed, 229 insertions(+) diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c index 1b3a3d9..6984387 100644 --- a/src/backend/access/transam/xlog.c +++ b/src/backend/access/transam/xlog.c @@ -79,6 +79,7 @@ #include "utils/relmapper.h" #include "utils/pg_rusage.h" #include "utils/snapmgr.h" +#include "utils/timeout.h" #include "utils/timestamp.h" extern uint32 bootstrap_data_checksum_version; @@ -397,6 +398,17 @@ static bool doRequestWalReceiverReply; */ static XLogRecPtr RedoStartLSN = InvalidXLogRecPtr; +/* + * Start timestamp of the operation that occur during startup process. + */ +static TimestampTz operationStartTimestamp; + +/* + * Indicates whether the startup progress interval mentioned by the user is + * elapsed or not. TRUE if timeout occurred. FALSE otherwise. + */ +static bool logStartupProgressTimeout; + /*---------- * Shared-memory data structures for XLOG control * @@ -7321,6 +7333,8 @@ StartupXLOG(void) (errmsg("redo starts at %X/%X", LSN_FORMAT_ARGS(ReadRecPtr)))); + InitStartupProgress(); + /* * main redo apply loop */ @@ -7328,6 +7342,8 @@ StartupXLOG(void) { bool switchedTLI = false; + LogStartupProgress(RECOVERY_IN_PROGRESS, NULL); + #ifdef WAL_DEBUG if (XLOG_DEBUG || (rmid == RM_XACT_ID && trace_recovery_messages <= DEBUG2) || @@ -7539,6 +7555,8 @@ StartupXLOG(void) * end of main redo apply loop */ + CloseStartupProgress(RECOVERY_END); + if (reachedRecoveryTarget) { if (!reachedConsistency) @@ -12935,3 +12953,146 @@ XLogRequestWalReceiverReply(void) { doRequestWalReceiverReply = true; } + +/* + * Schedule a wakeup call for logging the progress of startup process. + */ +void +LogStartupProgressTimeoutHandler(void) +{ + logStartupProgressTimeout = true; +} + +/* + * Sets the start timestamp of the current operation and also enables the + * timeout for logging the progress of startup process. + */ +void +InitStartupProgress(void) +{ + operationStartTimestamp = GetCurrentTimestamp(); + enable_timeout_after(LOG_STARTUP_PROGRESS_TIMEOUT, + log_startup_progress_interval); +} + +/* + * Fetches the start timestamp of the current operation. + */ +TimestampTz +GetCurrentOperationStartTimestamp(void) +{ + return operationStartTimestamp; +} + +/* + * Returns a string which indicates the description of the operation performed + * during startup process. + */ +static char * +get_startup_process_operation_string(StartupProcessOp operation) +{ + switch (operation) + { + case SYNCFS_IN_PROGRESS: + return gettext_noop("Syncing data directory (syncfs)"); + case FSYNC_IN_PROGRESS: + return gettext_noop("Syncing data directory (fsync)"); + case RECOVERY_IN_PROGRESS: + return gettext_noop("Performing crash recovery"); + case RESET_UNLOGGED_REL_IN_PROGRESS: + return gettext_noop("Resetting unlogged relations"); + case SYNCFS_END: + return gettext_noop("Data directory sync (syncfs) complete"); + case FSYNC_END: + return gettext_noop("Data directory sync (fsync) complete"); + case RECOVERY_END: + return gettext_noop("Crash recovery complete"); + case RESET_UNLOGGED_REL_END: + return gettext_noop("Unlogged relations reset"); + default: + ereport(ERROR, + (errmsg("unrecognized operation (%d) in startup progress update", + operation))); + } +} + +/* + * Logs the progress of the operations performed during startup process. + */ +void +LogStartupProgress(StartupProcessOp operation, const char *path) +{ + long secs; + int usecs; + int msecs; + + /* If the feature is disabled, then no need to proceed further. */ + if (log_startup_progress_interval < 0) + return; + + /* Return if any invalid operation */ + if (operation >= SYNCFS_END) + return; + + /* If the timeout has not occurred, then no need to log the details. */ + if (!logStartupProgressTimeout) + return; + + /* Timeout has occurred. Log the necessary details. */ + TimestampDifference(GetCurrentOperationStartTimestamp(), + GetCurrentTimestamp(), + &secs, &usecs); + msecs = usecs / 1000; + + if (operation == RECOVERY_IN_PROGRESS) + ereport(LOG, + (errmsg("%s, elapsed time: %ld.%03d ms, current LSN: %X/%X", + get_startup_process_operation_string(operation), + secs * 1000 + msecs, usecs % 1000, + LSN_FORMAT_ARGS(ReadRecPtr)))); + else + ereport(LOG, + (errmsg("%s, elapsed time: %ld.%03d ms, current path: %s", + get_startup_process_operation_string(operation), + secs * 1000 + msecs, usecs % 1000, + path))); + + /* + * Set the timeout flag to false and enable the timeout to log the progress if + * any in the future. + */ + logStartupProgressTimeout = false; + enable_timeout_after(LOG_STARTUP_PROGRESS_TIMEOUT, + log_startup_progress_interval); +} + +/* + * Logs the completion of the operation performed during startup process and + * disables the timeout used for logging the progress. + */ +void CloseStartupProgress(StartupProcessOp operation) +{ + long secs; + int usecs; + int msecs; + + /* If the feature is disabled, then no need to proceed further. */ + if (log_startup_progress_interval < 0) + return; + + /* Return if any invalid operation */ + if (operation < SYNCFS_END) + return; + + TimestampDifference(GetCurrentOperationStartTimestamp(), + GetCurrentTimestamp(), + &secs, &usecs); + msecs = usecs / 1000; + + ereport(LOG, + (errmsg("%s after %ld.%03d ms", + get_startup_process_operation_string(operation), + secs * 1000 + msecs, usecs % 1000))); + + disable_timeout(LOG_STARTUP_PROGRESS_TIMEOUT, false); +} diff --git a/src/backend/postmaster/startup.c b/src/backend/postmaster/startup.c index 69077bd..08c271c 100644 --- a/src/backend/postmaster/startup.c +++ b/src/backend/postmaster/startup.c @@ -232,6 +232,7 @@ StartupProcessMain(void) RegisterTimeout(STANDBY_DEADLOCK_TIMEOUT, StandbyDeadLockHandler); RegisterTimeout(STANDBY_TIMEOUT, StandbyTimeoutHandler); RegisterTimeout(STANDBY_LOCK_TIMEOUT, StandbyLockTimeoutHandler); + RegisterTimeout(LOG_STARTUP_PROGRESS_TIMEOUT, LogStartupProgressTimeoutHandler); /* * Unblock signals (they were blocked when the postmaster forked us) diff --git a/src/backend/storage/file/fd.c b/src/backend/storage/file/fd.c index e8cd7ef..e4d9a1e 100644 --- a/src/backend/storage/file/fd.c +++ b/src/backend/storage/file/fd.c @@ -100,6 +100,7 @@ #include "storage/ipc.h" #include "utils/guc.h" #include "utils/resowner_private.h" +#include "utils/timeout.h" /* Define PG_FLUSH_DATA_WORKS if we have an implementation for pg_flush_data */ #if defined(HAVE_SYNC_FILE_RANGE) @@ -3290,6 +3291,8 @@ do_syncfs(const char *path) { int fd; + LogStartupProgress(SYNCFS_IN_PROGRESS, path); + fd = OpenTransientFile(path, O_RDONLY); if (fd < 0) { @@ -3366,6 +3369,8 @@ SyncDataDirectory(void) DIR *dir; struct dirent *de; + InitStartupProgress(); + /* * On Linux, we don't have to open every single file one by one. We * can use syncfs() to sync whole filesystems. We only expect @@ -3392,10 +3397,14 @@ SyncDataDirectory(void) /* If pg_wal is a symlink, process that too. */ if (xlog_is_symlink) do_syncfs("pg_wal"); + + CloseStartupProgress(SYNCFS_END); return; } #endif /* !HAVE_SYNCFS */ + InitStartupProgress(); + /* * If possible, hint to the kernel that we're soon going to fsync the data * directory and its contents. Errors in this step are even less @@ -3421,6 +3430,8 @@ SyncDataDirectory(void) if (xlog_is_symlink) walkdir("pg_wal", datadir_fsync_fname, false, LOG); walkdir("pg_tblspc", datadir_fsync_fname, true, LOG); + + CloseStartupProgress(FSYNC_END); } /* @@ -3460,6 +3471,7 @@ walkdir(const char *path, continue; snprintf(subpath, sizeof(subpath), "%s/%s", path, de->d_name); + LogStartupProgress(FSYNC_IN_PROGRESS, path); switch (get_dirent_type(subpath, de, process_symlinks, elevel)) { diff --git a/src/backend/storage/file/reinit.c b/src/backend/storage/file/reinit.c index 40c758d..0b4e62d 100644 --- a/src/backend/storage/file/reinit.c +++ b/src/backend/storage/file/reinit.c @@ -16,12 +16,14 @@ #include <unistd.h> +#include "access/xlog.h" #include "common/relpath.h" #include "storage/copydir.h" #include "storage/fd.h" #include "storage/reinit.h" #include "utils/hsearch.h" #include "utils/memutils.h" +#include "utils/timeout.h" static void ResetUnloggedRelationsInTablespaceDir(const char *tsdirname, int op); @@ -75,6 +77,8 @@ ResetUnloggedRelations(int op) */ spc_dir = AllocateDir("pg_tblspc"); + InitStartupProgress(); + while ((spc_de = ReadDir(spc_dir, "pg_tblspc")) != NULL) { if (strcmp(spc_de->d_name, ".") == 0 || @@ -86,6 +90,7 @@ ResetUnloggedRelations(int op) ResetUnloggedRelationsInTablespaceDir(temp_path, op); } + LogStartupProgress(RESET_UNLOGGED_REL_END, NULL); FreeDir(spc_dir); /* @@ -136,6 +141,7 @@ ResetUnloggedRelationsInTablespaceDir(const char *tsdirname, int op) snprintf(dbspace_path, sizeof(dbspace_path), "%s/%s", tsdirname, de->d_name); + LogStartupProgress(RESET_UNLOGGED_REL_IN_PROGRESS, dbspace_path); ResetUnloggedRelationsInDbspaceDir(dbspace_path, op); } diff --git a/src/backend/utils/misc/guc.c b/src/backend/utils/misc/guc.c index 68b62d5..56f3126 100644 --- a/src/backend/utils/misc/guc.c +++ b/src/backend/utils/misc/guc.c @@ -663,6 +663,12 @@ static char *recovery_target_lsn_string; /* should be static, but commands/variable.c needs to get at this */ char *role_string; +/* + * The interval between each progress update of the operations that occur + * during startup process. + */ +int log_startup_progress_interval = -1; + /* * Displayable names for context types (enum GucContext) @@ -3539,6 +3545,18 @@ static struct config_int ConfigureNamesInt[] = check_client_connection_check_interval, NULL, NULL }, + { + {"log_startup_progress_interval", PGC_SIGHUP, LOGGING_WHEN, + gettext_noop("Sets the time interval between each progress update " + "of the startup process."), + gettext_noop("Zero logs all messages. -1 turns this feature off."), + GUC_UNIT_MS + }, + &log_startup_progress_interval, + -1, -1, INT_MAX, + NULL, NULL, NULL + }, + /* End-of-list marker */ { {NULL, 0, 0, NULL, NULL}, NULL, 0, 0, 0, NULL, NULL, NULL diff --git a/src/backend/utils/misc/postgresql.conf.sample b/src/backend/utils/misc/postgresql.conf.sample index ddbb6dc..3c72d9f 100644 --- a/src/backend/utils/misc/postgresql.conf.sample +++ b/src/backend/utils/misc/postgresql.conf.sample @@ -521,6 +521,12 @@ # are logged regardless of their duration; 1.0 logs all # statements from all transactions, 0.0 never logs +#log_startup_progress_interval = -1 # Sets the time interval between each + # progress update of the startup process. + # -1 disables the feature, zero logs all + # messages, > 0 indicates the interval in + # milliseconds. + # - What to Log - #debug_print_parse = off diff --git a/src/include/access/xlog.h b/src/include/access/xlog.h index 77187c1..34380ba 100644 --- a/src/include/access/xlog.h +++ b/src/include/access/xlog.h @@ -287,6 +287,22 @@ typedef enum WALAvailability WALAVAIL_REMOVED /* WAL segment has been removed */ } WALAvailability; +/* + * Codes of the operations performed during startup process + */ +typedef enum StartupProcessOp +{ + SYNCFS_IN_PROGRESS, + FSYNC_IN_PROGRESS, + RECOVERY_IN_PROGRESS, + RESET_UNLOGGED_REL_IN_PROGRESS, + DUMMY, + SYNCFS_END, + FSYNC_END, + RECOVERY_END, + RESET_UNLOGGED_REL_END +} StartupProcessOp; + struct XLogRecData; extern XLogRecPtr XLogInsertRecord(struct XLogRecData *rdata, @@ -391,6 +407,12 @@ extern void do_pg_abort_backup(int code, Datum arg); extern void register_persistent_abort_backup_handler(void); extern SessionBackupState get_backup_status(void); +extern TimestampTz GetCurrentOperationStartTimestamp(void); +extern void InitStartupProgress(void); +extern void LogStartupProgress(StartupProcessOp operation, const char *path); +extern void CloseStartupProgress(StartupProcessOp operation); +extern void LogStartupProgressTimeoutHandler(void); + /* File path names (all relative to $PGDATA) */ #define RECOVERY_SIGNAL_FILE "recovery.signal" #define STANDBY_SIGNAL_FILE "standby.signal" diff --git a/src/include/utils/guc.h b/src/include/utils/guc.h index a7c3a49..7c12632 100644 --- a/src/include/utils/guc.h +++ b/src/include/utils/guc.h @@ -282,6 +282,8 @@ extern int tcp_user_timeout; extern bool trace_sort; #endif +extern int log_startup_progress_interval; + /* * Functions exported by guc.c */ diff --git a/src/include/utils/timeout.h b/src/include/utils/timeout.h index 93e6a69..ef892dd 100644 --- a/src/include/utils/timeout.h +++ b/src/include/utils/timeout.h @@ -33,6 +33,7 @@ typedef enum TimeoutId IDLE_IN_TRANSACTION_SESSION_TIMEOUT, IDLE_SESSION_TIMEOUT, CLIENT_CONNECTION_CHECK_TIMEOUT, + LOG_STARTUP_PROGRESS_TIMEOUT, /* First user-definable timeout reason */ USER_TIMEOUT, /* Maximum number of timeout reasons */ -- 1.8.3.1
^ permalink raw reply [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
@ 2021-04-20 12:22 ` Magnus Hagander <magnus@hagander.net>
  5 siblings, 0 replies; 38+ messages in thread

From: Magnus Hagander @ 2021-04-20 12:22 UTC (permalink / raw)
  To: Robert Haas <robertmhaas@gmail.com>; +Cc: pgsql-hackers

On Mon, Apr 19, 2021 at 7:55 PM Robert Haas <robertmhaas@gmail.com> wrote:
>
> Hi,
>
> I've noticed that customers not infrequently complain that they start
> postgres and then the system doesn't come up for a while and they have
> no idea what's going on and are (understandably) worried. There are
> probably a number of reasons why this can happen, but the ones that
> seem to come up most often in my experience are (1) SyncDataDirectory
> takes a long time, (b) ResetUnloggedRelations takes a long time, and
> (c) there's a lot of WAL to apply so that takes a long time. It's
> possible to distinguish this last case from the other two by looking
> at the output of 'ps', but that's not super-convenient if your normal
> method of access to the server is via libpq, and it only works if you
> are monitoring it as it's happening rather than looking at the logs
> after-the-fact. I am not sure there's any real way to distinguish the
> other two cases without using strace or gdb or similar.
>
> It seems to me that we could do better. One approach would be to try
> to issue a log message periodically - maybe once per minute, or some
> configurable interval, e.g. perhaps add messages something like this:
>
> LOG:  still syncing data directory, elapsed time %ld.%03d ms, current path %s
> LOG:  data directory sync complete after %ld.%03d ms
> LOG:  still resetting unlogged relations, elapsed time %ld.%03d ms,
> current path %s
> LOG:  unlogged relations reset after %ld.%03d ms
> LOG:  still performing crash recovery, elapsed time %ld.%03d ms,
> current LSN %08X/%08X
>
> We already have a message when redo is complete, so there's no need
> for another one. The implementation here doesn't seem too hard either:
> the startup process would set a timer, when the timer expires the
> signal handler sets a flag, at a convenient point we notice the flag
> is set and responding by printing a message and clearing the flag.
>
> Another possible approach would be to accept connections for
> monitoring purposes even during crash recovery. We can't allow access
> to any database at that point, since the system might not be
> consistent, but we could allow something like a replication connection
> (the non-database-associated variant). Maybe it would be precisely a
> replication connection and we'd just refuse all but a subset of
> commands, or maybe it would be some other kinds of thing. But either
> way you'd be able to issue a command in some mini-language saying "so,
> tell me how startup is going" and it would reply with a result set of
> some kind.
>
> If I had to pick one of these two ideas, I'd pick the one the
> log-based solution, since it seems easier to access and simplifies
> retrospective analysis, but I suspect SQL access would be quite useful
> for some users too, especially in cloud environments where "just log
> into the machine and have a look" is not an option.
>
> Thoughts?

(Ugh. Did reply instead of reply-all. Surely I should know that by
now... Here's a re-send!)

+1 for the log based one.

In general I'm usually against the log based one, but something over
the replication protocol is really not going to help a lot of people
who are in this situation. They may not even have permissions to log
in, and any kind of monitoring system would fail to work as well. And
can we even log users in at this point? We can't get the list of
roles... If we could, I would say it's probably better to allow the
login in a regular connection, but then immediately throw an error and
give this error a more detailed message if the user has monitoring
permissions.

But against either of those, the log based method is certainly a lot
easier to build :)

And FWIW, I believe most -- probably all -- cloud environments do give
an interface to view the log at least, so the log based solution would
work there as well. Maybe not as convenient, but it would work.

-- 
 Magnus Hagander
 Me: https://www.hagander.net/
 Work: https://www.redpill-linpro.com/





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
@ 2021-04-20 20:28 ` Andres Freund <andres@anarazel.de>
  2021-04-20 20:54   ` Re: when the startup process doesn't Alvaro Herrera <alvherre@alvh.no-ip.org>
  5 siblings, 1 reply; 38+ messages in thread

From: Andres Freund @ 2021-04-20 20:28 UTC (permalink / raw)
  To: Robert Haas <robertmhaas@gmail.com>; +Cc: pgsql-hackers

Hi,

On 2021-04-19 13:55:13 -0400, Robert Haas wrote:
> Another possible approach would be to accept connections for
> monitoring purposes even during crash recovery. We can't allow access
> to any database at that point, since the system might not be
> consistent, but we could allow something like a replication connection
> (the non-database-associated variant). Maybe it would be precisely a
> replication connection and we'd just refuse all but a subset of
> commands, or maybe it would be some other kinds of thing. But either
> way you'd be able to issue a command in some mini-language saying "so,
> tell me how startup is going" and it would reply with a result set of
> some kind.

The hard part about this seems to be how to perform authentication -
obviously we can't do catalog lookups for users at that time.

If that weren't the issue, we could easily do much better than now, by
just providing an errdetail() with recovery progress information. But we
presumably don't want to spray such information to unauthenticated
connection attempts.


I've vaguely wondered before whether it'd be worth having something like
an "admin" socket somewhere in the data directory. Which explicitly
wouldn't require authentication, have the cluster owner as the user,
etc.  That'd not just be useful for monitoring during recovery, but also
make some interactions with the server easier for admin tools I think.



> If I had to pick one of these two ideas, I'd pick the one the
> log-based solution, since it seems easier to access and simplifies
> retrospective analysis, but I suspect SQL access would be quite useful
> for some users too, especially in cloud environments where "just log
> into the machine and have a look" is not an option.

However, leaving aside the implementation effort, the crazy idea
above would not easily address the issue of only being accessible with
local access...

Greetings,

Andres Freund





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
  2021-04-20 20:28 ` Re: when the startup process doesn't Andres Freund <andres@anarazel.de>
@ 2021-04-20 20:54   ` Alvaro Herrera <alvherre@alvh.no-ip.org>
  0 siblings, 0 replies; 38+ messages in thread

From: Alvaro Herrera @ 2021-04-20 20:54 UTC (permalink / raw)
  To: Andres Freund <andres@anarazel.de>; +Cc: Robert Haas <robertmhaas@gmail.com>; pgsql-hackers

On 2021-Apr-20, Andres Freund wrote:

> On 2021-04-19 13:55:13 -0400, Robert Haas wrote:
> > Another possible approach would be to accept connections for
> > monitoring purposes even during crash recovery. We can't allow access
> > to any database at that point, since the system might not be
> > consistent, but we could allow something like a replication connection
> > (the non-database-associated variant). Maybe it would be precisely a
> > replication connection and we'd just refuse all but a subset of
> > commands, or maybe it would be some other kinds of thing. But either
> > way you'd be able to issue a command in some mini-language saying "so,
> > tell me how startup is going" and it would reply with a result set of
> > some kind.
> 
> The hard part about this seems to be how to perform authentication -
> obviously we can't do catalog lookups for users at that time.

Maybe a way to do this would involve some sort of monitoring cookie
that's obtained ahead of time (maybe at initdb time?) and is supplied to
the frontend by some OOB means.  Then frontend can present that during
startup to the server, which ascertains its legitimacy without having to
access catalogs.  Perhaps it even requires a specific pg_hba.conf rule.

-- 
Álvaro Herrera       Valdivia, Chile
"La verdad no siempre es bonita, pero el hambre de ella sí"





^ permalink  raw  reply  [nested|flat] 38+ messages in thread

* Re: when the startup process doesn't
  2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
@ 2021-04-20 21:11 ` SATYANARAYANA NARLAPURAM <satyanarlapuram@gmail.com>
  5 siblings, 0 replies; 38+ messages in thread

From: SATYANARAYANA NARLAPURAM @ 2021-04-20 21:11 UTC (permalink / raw)
  To: Robert Haas <robertmhaas@gmail.com>; pgsql-hackers

+1 for both log messages and allowing connections. I believe these two
complement each other.

In the cloud world, we oftentimes want to monitor the progress of the
recovery without connecting to the server as the operators don't
necessarily have the required permissions to connect and query. Secondly,
having this information in the log helps going back in time and understand
where Postgres spent time during recovery.

The ability to query the server provides real time information  and come
handy.

Thanks,
Satya



On Mon, Apr 19, 2021 at 10:55 AM Robert Haas <robertmhaas@gmail.com> wrote:

> Hi,
>
> I've noticed that customers not infrequently complain that they start
> postgres and then the system doesn't come up for a while and they have
> no idea what's going on and are (understandably) worried. There are
> probably a number of reasons why this can happen, but the ones that
> seem to come up most often in my experience are (1) SyncDataDirectory
> takes a long time, (b) ResetUnloggedRelations takes a long time, and
> (c) there's a lot of WAL to apply so that takes a long time. It's
> possible to distinguish this last case from the other two by looking
> at the output of 'ps', but that's not super-convenient if your normal
> method of access to the server is via libpq, and it only works if you
> are monitoring it as it's happening rather than looking at the logs
> after-the-fact. I am not sure there's any real way to distinguish the
> other two cases without using strace or gdb or similar.
>
> It seems to me that we could do better. One approach would be to try
> to issue a log message periodically - maybe once per minute, or some
> configurable interval, e.g. perhaps add messages something like this:
>
> LOG:  still syncing data directory, elapsed time %ld.%03d ms, current path
> %s
> LOG:  data directory sync complete after %ld.%03d ms
> LOG:  still resetting unlogged relations, elapsed time %ld.%03d ms,
> current path %s
> LOG:  unlogged relations reset after %ld.%03d ms
> LOG:  still performing crash recovery, elapsed time %ld.%03d ms,
> current LSN %08X/%08X
>
> We already have a message when redo is complete, so there's no need
> for another one. The implementation here doesn't seem too hard either:
> the startup process would set a timer, when the timer expires the
> signal handler sets a flag, at a convenient point we notice the flag
> is set and responding by printing a message and clearing the flag.
>
> Another possible approach would be to accept connections for
> monitoring purposes even during crash recovery. We can't allow access
> to any database at that point, since the system might not be
> consistent, but we could allow something like a replication connection
> (the non-database-associated variant). Maybe it would be precisely a
> replication connection and we'd just refuse all but a subset of
> commands, or maybe it would be some other kinds of thing. But either
> way you'd be able to issue a command in some mini-language saying "so,
> tell me how startup is going" and it would reply with a result set of
> some kind.
>
> If I had to pick one of these two ideas, I'd pick the one the
> log-based solution, since it seems easier to access and simplifies
> retrospective analysis, but I suspect SQL access would be quite useful
> for some users too, especially in cloud environments where "just log
> into the machine and have a look" is not an option.
>
> Thoughts?
>
> --
> Robert Haas
> EDB: http://www.enterprisedb.com
>
>
>

^ permalink  raw  reply  [nested|flat] 38+ messages in thread


end of thread, other threads:[~2021-06-17 11:27 UTC | newest]

Thread overview: 38+ messages (download: mbox mbox.gz follow: Atom feed)
-- links below jump to the message on this page --
2021-04-19 17:55 when the startup process doesn't Robert Haas <robertmhaas@gmail.com>
2021-04-19 23:16 ` Alvaro Herrera <alvherre@alvh.no-ip.org>
2021-04-20 00:30 ` Bruce Momjian <bruce@momjian.us>
2021-04-20 00:38 ` Thomas Munro <thomas.munro@gmail.com>
2021-04-20 00:44   ` Tom Lane <tgl@sss.pgh.pa.us>
2021-04-20 12:43     ` Robert Haas <robertmhaas@gmail.com>
2021-04-20 13:04       ` Magnus Hagander <magnus@hagander.net>
2021-04-20 15:17         ` Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
2021-04-20 17:32           ` Magnus Hagander <magnus@hagander.net>
2021-04-20 18:23             ` Tom Lane <tgl@sss.pgh.pa.us>
2021-04-20 18:51               ` Stephen Frost <sfrost@snowman.net>
2021-04-20 18:56                 ` Tom Lane <tgl@sss.pgh.pa.us>
2021-04-20 19:04                   ` Stephen Frost <sfrost@snowman.net>
2021-04-20 20:36                   ` Andres Freund <andres@anarazel.de>
2021-04-21 18:36                     ` Stephen Frost <sfrost@snowman.net>
2021-04-21 18:43                       ` Tom Lane <tgl@sss.pgh.pa.us>
2021-04-21 19:36                       ` Andres Freund <andres@anarazel.de>
2021-04-21 19:51                         ` Stephen Frost <sfrost@snowman.net>
2021-04-21 20:00                           ` Andres Freund <andres@anarazel.de>
2021-04-21 20:28                             ` Stephen Frost <sfrost@snowman.net>
2021-04-21 20:55                               ` Tom Lane <tgl@sss.pgh.pa.us>
2021-04-21 21:00                                 ` Andres Freund <andres@anarazel.de>
2021-04-21 21:04                                   ` Stephen Frost <sfrost@snowman.net>
2021-04-21 20:58                               ` Andres Freund <andres@anarazel.de>
2021-04-21 23:09                         ` Jehan-Guillaume de Rorthais <jgdr@dalibo.com>
2021-06-04 14:19                           ` Nitin Jadhav <nitinjadhavpostgres@gmail.com>
2021-06-06 22:23                             ` Justin Pryzby <pryzby@telsasoft.com>
2021-06-07 13:21                               ` Robert Haas <robertmhaas@gmail.com>
2021-06-07 13:42                                 ` Tom Lane <tgl@sss.pgh.pa.us>
2021-06-09 11:39                                   ` Nitin Jadhav <nitinjadhavpostgres@gmail.com>
2021-06-09 16:19                                     ` Justin Pryzby <pryzby@telsasoft.com>
2021-06-10 09:49                                       ` Nitin Jadhav <nitinjadhavpostgres@gmail.com>
2021-06-10 10:01                                         ` Justin Pryzby <pryzby@telsasoft.com>
2021-06-17 11:27                                           ` Nitin Jadhav <nitinjadhavpostgres@gmail.com>
2021-04-20 12:22 ` Magnus Hagander <magnus@hagander.net>
2021-04-20 20:28 ` Andres Freund <andres@anarazel.de>
2021-04-20 20:54   ` Alvaro Herrera <alvherre@alvh.no-ip.org>
2021-04-20 21:11 ` SATYANARAYANA NARLAPURAM <satyanarlapuram@gmail.com>

This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox