Subject: Re: [PATCH] Log PostgreSQL version number on startup
From: Peter Eisentraut <peter.eisentraut@2ndquadrant.com>
To: Christoph Berg <christoph.berg@credativ.de>,
 PostgreSQL Hackers <pgsql-hackers@postgresql.org>
References: <20181121144611.GJ15795@msg.credativ.de>
 <d5d50936-20b9-85f1-06bc-94a01c5040c1@2ndquadrant.com>
Openpgp: preference=signencrypt
Autocrypt: addr=peter.eisentraut@2ndquadrant.com; prefer-encrypt=mutual;
 keydata=
 xsFNBFUUt6kBEADZd9NNTBJbHmAXXJgPGOdd6Q73l80oifIVgn2tRxP9dYkCfTlo/yLqbKTl
 JNqTcyM6XrJDnB2sMEUGYCewYZXl+9C4bBJWyNqcEI1ae9u71vEq/fknFLArJ+2wN+f7QuRx
 Q8d94ZJAiJQ5g3fNk2HVeedCQCKP5dCzU+ZLt2dbsx1PDZLjTO9gf+JswWuGFb5wY5PZVM5V
 hq66Xk7ZJzHuARacza2RT7J2fkMmQBY+kr7L98Perb0GhafnlhXB0PvUB+N3xpmggMfwuhTu
 BngS/G/r3GvemxJuFxouw8xsMqrsfdksJXA2gLXYtwRCssdPV3PO0rlD9twqDo8URfIJ5fb6
 1g/MV8aTOKjg3Q8MpJPtkwJqN4o3PvbwYdedeFnOVkkYAJdu/aX1v1BeCBDu7Hy3sF52scD3
 pQbyQSl9vUDpTLarASAxNbAV0NRJE8dp4vfW6AH1ccryGiFqw/czPK/iN0+MT8wsjAW6WW4w
 hvjm5UPA1KTwi3ZT8eT5uycuH7QpuNk7LnGGXQ6KaRALFywzkr0A0V0AvFNa+l4wstMaXaB6
 dmMXyF0/hfryqyOeu1gAdq4q0/PNC2dPgb/6uoh4eMjN6A5GXcprilhz5DulmsilY21hfSoU
 S64ODed96pKhprsOxjZiDRsN1QM5MwB+uwVWUNfsX7fIxE0BrwARAQABzSdQZXRlciBFaXNl
 bnRyYXV0IDxwZXRlckBlaXNlbnRyYXV0Lm9yZz7CwXoEEwEIACQCGwMFCwkIBwMFFQoJCAsF
 FgIDAQACHgECF4AFAlUUuKQCGQEACgkQoZ8SQ+xBJp8llw//RbGoXnF72FZTlOFsnNyxnWbF
 vViPCfdAlZl1GGK9OYCvV1dp/956HuhB0wpaGQHiBmQfOPJf/jLOPjXFYm2iEChEycrBChuE
 j4TSYemMp5BSPILYk9Uwd16kVD/+U6fQfK6H5pOhfBvbM6asMnmpY2wQuvktxHvaGlytFw84
 EzFWNZtAZfxkw28w3AhIQkKe9hJanfyDL750RcbyEr8AAHty5IErrvS7tM5vQwIeh5BF26ND
 CyKPRdZgOgMpcwFfROKBDpAt052CgWIpNdhBdfIKlkCs4/ILxmC3rT/Mb/qZiHcoMMwEu6k+
 T7vRAFZZAk62Yrr/U8/vUGKlzRZQoo86fyojCfI0ibCIc0z8rwCVY9P40G9wD9BTCZS/z8Vh
 jjpBlNnIKw2hM6hbxavKndCJjFFJD08rXrTyrLF/of18xD37vNdYooP9VATB5QjOWFRrscSZ
 4a89e+to3m7YVnd4xdXwGp47dYusoax84C8tg1gZrH38ol9dPmnKX6GZrXeS7tH9k8VeUpJ8
 HQbRThQRWAT936QpYbLConBmOtmbLmjQOGtiXPo1oK57X/7U/WBja5vWmm2q+Yxtt+3uHGVg
 DdDU4CJpXo4lX0v2n3QV5EBSW9hjdF3bNfl6GFBb1pPEhqNcMDUc7zkx/2uENdAdk/BnqMgH
 umip7b0pVfvOwU0EVRS3qQEQAJf6p0P7D+hMYUgCPkvgrcz6OJYsAYdUMUmokfqmkKwK0oJM
 ew8TNGM53ocKAgQGma5f10rwbZNPlpVPNRX5hwUmwVlcwSut0oE+JfUBH7mpysWvpF05RKIy
 q9RCoJZrAbXS7Tig56A1QD8IcM00rERZMcCOlI1+q9m4u9AOI+0LyGGSH+VvoyDHD/Jew4R2
 TmPEF8Pu7lYiNYK88Q6u0kBkc+Tz3BNlyc6fi3HxnFfp0b75HLXPSTu2SwA/0Q31wHZXwrEU
 BR9KgSn/qbgy8ydPc97i82fhiFE3cbGexfPrQSMYmDGi+dcQ0s+AMQwC3XyMC0JkHpYUuFkR
 QdlIvaIhgFUUN2Vr4xF2ADaNTNFc4DYaiPHFAgHZw+3pZWqS4uIiWgJynrEaHw4F3QWU8/JB
 iyEWDhNq4WBrRA0u914TCCAoFOOKMnRdl8eJrRQKM/5/lXbHFjjlI/LDKhLRFsuQsnJJ3331
 RjCzpHPZG5/p5KR1RHiAXa0p/DW5lXyq21hS3kjDlleoHqOxCN/cy0Jgz7qLDq1vZoCl67Sy
 RAH60c2Xu4may9SVltmot0OzWVHdrfS+85FQGp9580DaeLio7YMFKy2bfEvwQJ/c9xD2QPB+
 oSb3V8ueSznXBG5+dyfOsZFRPxceA0wA2rSWZSjxLdKxvyGTj9vsCjaDu13rABEBAAHCwV8E
 GAEIAAkFAlUUt6kCGwwACgkQoZ8SQ+xBJp+HJhAAxmSTsC5y7p9Zu+nnLpucv/h88oEx985e
 qWeXzQiwM3pfRZS+PdTH9TyzHK0KOgKoAiubk0vt+BrT91D9d0G5kVQaTctAErGBoMkTaZJT
 XVEcNphiPzysdSqvprjojMp1y7rG8AP+Xd6m0rE1LRnkRRm8HyI8vdXsuLQPITGWXDLMjaNq
 AOV3BUnzkgtjMuIYw7SCr+12ZOb5dEKvaG4kjC4kaJ/TLbuBhVANcXkC90yp0AOZLs/cB1Dj
 OAXno/RUUruJ3r27a+pFv768UAi9QWcdw58yPxreMNMLqAgsS9oTHwHfGNWcB2dJ4UW+GMLJ
 hTf9TjQ2f+N/sIx5XMQ9pYw6CAJMK29qPx6/ZayrPxf22EXf0D3zTwIEZgwfSkynFVwV25L7
 awQq60fifdMYheSxq7GbhpsixmcD+e161cCmLIt75YDt5bQ0B1yf7EmxG8n7pGZAOM6LoNsU
 fkSldba5XVwh8LuN5mK0nQBELGW6Os4TDq4REggLpfcvFC215zpuo0iCGnmE/Bns4nowqUSP
 u4tkWL+nxW4qgv8wo8HJ52jd79EJ8iqfIBoidBfy9AIUiEUApGQzWPu6yWcI8fY0rN5D+tc+
 Yw1Zt6Mm+huYJpgCRsTcfzEcahnBn521CWcWvhW1ff3KFileFMtNmnBBhMncmRKHphtTKEpN
 3jI=
Organization: 2ndQuadrant
Message-ID: <92bfdfdf-4164-aec5-4e32-c26e67821c38@2ndquadrant.com>
Date: Wed, 16 Jan 2019 20:58:48 +0100
User-Agent: Mozilla/5.0 (Macintosh; Intel Mac OS X 10.13; rv:52.0)
 Gecko/20100101 Thunderbird/52.9.1
MIME-Version: 1.0
In-Reply-To: <d5d50936-20b9-85f1-06bc-94a01c5040c1@2ndquadrant.com>
Content-Type: multipart/mixed;
 boundary="------------67C6EBB3000527E5D39CEFC3"
Content-Language: en-US
Precedence: bulk

This is a multi-part message in MIME format.
--------------67C6EBB3000527E5D39CEFC3
Content-Type: text/plain; charset=windows-1252
Content-Transfer-Encoding: 7bit

On 05/01/2019 15:53, Peter Eisentraut wrote:
> On 21/11/2018 15:46, Christoph Berg wrote:
>> A startup looks like this:
>>
>> 2018-11-21 15:19:47.259 CET [24453] LOG:  listening on IPv6 address "::1", port 5431
>> 2018-11-21 15:19:47.259 CET [24453] LOG:  listening on IPv4 address "127.0.0.1", port 5431
>> 2018-11-21 15:19:47.315 CET [24453] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5431"
>> 2018-11-21 15:19:47.394 CET [24453] LOG:  starting PostgreSQL 12devel on x86_64-pc-linux-gnu, compiled by gcc (Debian 8.2.0-9) 8.2.0, 64-bit
>> 2018-11-21 15:19:47.426 CET [24454] LOG:  database system was shut down at 2018-11-21 15:15:35 CET
>> 2018-11-21 15:19:47.460 CET [24453] LOG:  database system is ready to accept connections
>>
>> (I'd rather put the start message before the listening messages, but I
>> think the startup message should be logged via logging_collector, and
>> listening is logged before the log file is opened.)
> 
> Why don't we start the logging collector before opening the sockets?

Specifically, something like the attached.

This keeps the dynamic module loading before the logging collector
start, so we see those error messages on stderr, but then the setting up
of the sockets would get logged.

-- 
Peter Eisentraut              http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

--------------67C6EBB3000527E5D39CEFC3
Content-Type: text/plain; charset=UTF-8; x-mac-type="0"; x-mac-creator="0";
 name="0001-postmaster-Start-syslogger-earlier.patch"
Content-Transfer-Encoding: 7bit
Content-Disposition: attachment;
 filename="0001-postmaster-Start-syslogger-earlier.patch"

From 0a482552d26488ec5ce8e4d7bad12bf25ba44c8b Mon Sep 17 00:00:00 2001
From: Peter Eisentraut <peter@eisentraut.org>
Date: Wed, 16 Jan 2019 17:32:01 +0100
Subject: [PATCH] postmaster: Start syslogger earlier

XXX
---
 src/backend/postmaster/postmaster.c | 120 ++++++++++++++--------------
 1 file changed, 60 insertions(+), 60 deletions(-)

diff --git a/src/backend/postmaster/postmaster.c b/src/backend/postmaster/postmaster.c
index a707d4d465..36efd908bb 100644
--- a/src/backend/postmaster/postmaster.c
+++ b/src/backend/postmaster/postmaster.c
@@ -992,6 +992,66 @@ PostmasterMain(int argc, char *argv[])
 	 */
 	InitializeMaxBackends();
 
+	/*
+	 * Initialize pipe (or process handle on Windows) that allows children to
+	 * wake up from sleep on postmaster death.
+	 */
+	InitPostmasterDeathWatchHandle();
+
+	/*
+	 * Forcibly remove the files signaling a standby promotion request.
+	 * Otherwise, the existence of those files triggers a promotion too early,
+	 * whether a user wants that or not.
+	 *
+	 * This removal of files is usually unnecessary because they can exist
+	 * only during a few moments during a standby promotion. However there is
+	 * a race condition: if pg_ctl promote is executed and creates the files
+	 * during a promotion, the files can stay around even after the server is
+	 * brought up to new master. Then, if new standby starts by using the
+	 * backup taken from that master, the files can exist at the server
+	 * startup and should be removed in order to avoid an unexpected
+	 * promotion.
+	 *
+	 * Note that promotion signal files need to be removed before the startup
+	 * process is invoked. Because, after that, they can be used by
+	 * postmaster's SIGUSR1 signal handler.
+	 */
+	RemovePromoteSignalFiles();
+
+	/* Do the same for logrotate signal file */
+	RemoveLogrotateSignalFiles();
+
+	/* Remove any outdated file holding the current log filenames. */
+	if (unlink(LOG_METAINFO_DATAFILE) < 0 && errno != ENOENT)
+		ereport(LOG,
+				(errcode_for_file_access(),
+				 errmsg("could not remove file \"%s\": %m",
+						LOG_METAINFO_DATAFILE)));
+
+	/*
+	 * If enabled, start up syslogger collection subprocess
+	 */
+	SysLoggerPID = SysLogger_Start();
+
+	/*
+	 * Reset whereToSendOutput from DestDebug (its starting state) to
+	 * DestNone. This stops ereport from sending log messages to stderr unless
+	 * Log_destination permits.  We don't do this until the postmaster is
+	 * fully launched, since startup failures may as well be reported to
+	 * stderr.
+	 *
+	 * If we are in fact disabling logging to stderr, first emit a log message
+	 * saying so, to provide a breadcrumb trail for users who may not remember
+	 * that their logging is configured to go somewhere else.
+	 */
+	if (!(Log_destination & LOG_DESTINATION_STDERR))
+		ereport(LOG,
+				(errmsg("ending log output to stderr"),
+				 errhint("Future log output will go to log destination \"%s\".",
+						 Log_destination_string)));
+
+	whereToSendOutput = DestNone;
+
 	/*
 	 * Establish input sockets.
 	 *
@@ -1183,12 +1243,6 @@ PostmasterMain(int argc, char *argv[])
 	 */
 	set_stack_base();
 
-	/*
-	 * Initialize pipe (or process handle on Windows) that allows children to
-	 * wake up from sleep on postmaster death.
-	 */
-	InitPostmasterDeathWatchHandle();
-
 #ifdef WIN32
 
 	/*
@@ -1242,60 +1296,6 @@ PostmasterMain(int argc, char *argv[])
 	 */
 	RemovePgTempFiles();
 
-	/*
-	 * Forcibly remove the files signaling a standby promotion request.
-	 * Otherwise, the existence of those files triggers a promotion too early,
-	 * whether a user wants that or not.
-	 *
-	 * This removal of files is usually unnecessary because they can exist
-	 * only during a few moments during a standby promotion. However there is
-	 * a race condition: if pg_ctl promote is executed and creates the files
-	 * during a promotion, the files can stay around even after the server is
-	 * brought up to new master. Then, if new standby starts by using the
-	 * backup taken from that master, the files can exist at the server
-	 * startup and should be removed in order to avoid an unexpected
-	 * promotion.
-	 *
-	 * Note that promotion signal files need to be removed before the startup
-	 * process is invoked. Because, after that, they can be used by
-	 * postmaster's SIGUSR1 signal handler.
-	 */
-	RemovePromoteSignalFiles();
-
-	/* Do the same for logrotate signal file */
-	RemoveLogrotateSignalFiles();
-
-	/* Remove any outdated file holding the current log filenames. */
-	if (unlink(LOG_METAINFO_DATAFILE) < 0 && errno != ENOENT)
-		ereport(LOG,
-				(errcode_for_file_access(),
-				 errmsg("could not remove file \"%s\": %m",
-						LOG_METAINFO_DATAFILE)));
-
-	/*
-	 * If enabled, start up syslogger collection subprocess
-	 */
-	SysLoggerPID = SysLogger_Start();
-
-	/*
-	 * Reset whereToSendOutput from DestDebug (its starting state) to
-	 * DestNone. This stops ereport from sending log messages to stderr unless
-	 * Log_destination permits.  We don't do this until the postmaster is
-	 * fully launched, since startup failures may as well be reported to
-	 * stderr.
-	 *
-	 * If we are in fact disabling logging to stderr, first emit a log message
-	 * saying so, to provide a breadcrumb trail for users who may not remember
-	 * that their logging is configured to go somewhere else.
-	 */
-	if (!(Log_destination & LOG_DESTINATION_STDERR))
-		ereport(LOG,
-				(errmsg("ending log output to stderr"),
-				 errhint("Future log output will go to log destination \"%s\".",
-						 Log_destination_string)));
-
-	whereToSendOutput = DestNone;
-
 	/*
 	 * Initialize stats collection subsystem (this does NOT start the
 	 * collector process!)
-- 
2.20.1


--------------67C6EBB3000527E5D39CEFC3--