Date: Sun, 6 Jun 2021 17:23:05 -0500
From: Justin Pryzby <pryzby@telsasoft.com>
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@postgresql.org
Subject: Re: when the startup process doesn't
Message-ID: <20210606222305.GZ14099@telsasoft.com>
References: <20210420171720.56599607@firost>
 <CABUevEyTBiiDvjdKo5h=gj6W1uL6i4jOOV4nur0YZsuKvKRVXw@mail.gmail.com>
 <631849.1618942988@sss.pgh.pa.us>
 <20210420185150.GL20766@tamriel.snowman.net>
 <633337.1618945018@sss.pgh.pa.us>
 <20210420203642.nvxvolm37f2k6prj@alap3.anarazel.de>
 <20210421183624.GP20766@tamriel.snowman.net>
 <20210421193605.cubavrq7q5bqkf4i@alap3.anarazel.de>
 <20210422010919.4b655015@firost>
 <CAMm1aWYAjwui2OrY6TSvVF8N9YLdRdnO5BUS-t5GDR60X1FanQ@mail.gmail.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: 
 <CAMm1aWYAjwui2OrY6TSvVF8N9YLdRdnO5BUS-t5GDR60X1FanQ@mail.gmail.com>
User-Agent: Mutt/1.9.4 (2018-02-28)
Archived-At: 
 <https://www.postgresql.org/message-id/20210606222305.GZ14099%40telsasoft.com>
Precedence: bulk

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