Re: [BUGS] Missing error message on missing ssl-key-files

PostgreSQL 8.1.5 and 8.2.1

both on W2K3, installed from the standard win32 msi installer.

Problem:

in postgresql.conf

ssl=on

but the files server.key etc. are NOT present.

Result: PostgreSQL service does not start. And no error message in any
log I could access: nothing in the Windows Event Log, nothing in the
pg_log (not even starts a file)

[in this case it was me doing the SSL-setup, missing to copy the key
files; BUT... they could get deleted / made inaccessible a later time,
and THEN it get's impossible to diagnose the problem]

Proposed solution:
write an error message to pg_log/ or windows event log on missing
ssl-server-key-files.

Harald

--
GHUM Harald Massa
persuadere et programmare
Harald Armin Massa
Reinsburgstraße 202b
70197 Stuttgart
0173/9409607
-
Python: the only language with more web frameworks than keywords.

Harald Armin Massa wrote:
> PostgreSQL 8.1.5 and 8.2.1
>
> both on W2K3, installed from the standard win32 msi installer.
>
> Problem:
>
> in postgresql.conf
>
> ssl=on
>
> but the files server.key etc. are NOT present.
>
> Result: PostgreSQL service does not start. And no error message in any
> log I could access: nothing in the Windows Event Log, nothing in the
> pg_log (not even starts a file)
>
> [in this case it was me doing the SSL-setup, missing to copy the key
> files; BUT... they could get deleted / made inaccessible a later time,
> and THEN it get's impossible to diagnose the problem]
>
> Proposed solution:
> write an error message to pg_log/ or windows event log on missing
> ssl-server-key-files.

I took a quick look at this, and it's certainly correct. If I change the
log_destination to be eventlog, it works and logs the proper error message.

This may show a much bigger problem. When we have set redirect_stderr
(which is what the MSI installer does by default), what happens to
everything that is logged *before* SysLogger_Start()? There are a lot of
startup things that happen then, but where does the output go?

I'm thinking we need a check in elog.c on the:
if ((!Redirect_stderr || am_syslogger) && pgwin32_is_service())
write_eventlog(edata->elevel, buf.data);

line, that checks if the syslogger process has been started yet. So it'd
be something like
if ((!Redirect_stderr || am_syslogger || syslogger_not_started_yet) &&
pgwin32_is_service())

Does that seem reasonable? Or am I looking at this the wrong way?

//Magnus

Magnus Hagander <magnus(at)hagander(dot)net> writes:
> I'm thinking we need a check in elog.c on the:
> if ((!Redirect_stderr || am_syslogger) && pgwin32_is_service())
> write_eventlog(edata->elevel, buf.data);
> line, that checks if the syslogger process has been started yet.

[ shrug... ] None of those other variables are guaranteed correct at
process start, either...

regards, tom lane

On Mon, Jan 29, 2007 at 09:56:16PM -0500, Tom Lane wrote:
> Magnus Hagander <magnus(at)hagander(dot)net> writes:
> > I'm thinking we need a check in elog.c on the:
> > if ((!Redirect_stderr || am_syslogger) && pgwin32_is_service())
> > write_eventlog(edata->elevel, buf.data);
> > line, that checks if the syslogger process has been started yet.
>
> [ shrug... ] None of those other variables are guaranteed correct at
> process start, either...

am_syslogger is inialized to "false" by default, so that one is pretty
safe (it' sonly set to true when inside the actual syslogger, which will
of course not happen in the postmaster). And in the syslogger, it's set
at the very top.

Redirect_stderr is initialized to false by default. Which means that
until redirect_stderr is set (=when we read the postgresql.conf file),
the above will alrady evaluate to write to the eventlog (per the
!Redirect_stderr).

Thus, we only need to cover the time between setting Redirect_stderr to
true (which happens when we read the config file) to starting of the
syslogger. Looking in postmaster.c, there are several errors that
happen at this point that will use write_stderr, but others (like SSL)
are functoins called that will call elog.

So I think we either need to add this check, or we need to start the
syslogger much sooner. In fact, we need this check anyway, because there
will always be a window between the two where other GUC variables are
set and can cause an error to be logged.

So I still tthink it's a good idea. Even though it doesn't solve every
case, it solves a lot of them I think. And more importantly on that, I
don't see how it would *break* anything (given that it still fires only
when running as a service, when everything on stderr is just thrown away
anyway). Do you see suhc a failure case?

//Magnus

Magnus Hagander <magnus(at)hagander(dot)net> writes:
> So I still tthink it's a good idea. Even though it doesn't solve every
> case, it solves a lot of them I think. And more importantly on that, I
> don't see how it would *break* anything (given that it still fires only
> when running as a service, when everything on stderr is just thrown away
> anyway). Do you see suhc a failure case?

The case I'm worried about is subprocess startup, where we haven't yet
been able to re-set any of these variables correctly. And yes, I think
it's an issue: if a DBA is expecting to find PG error messages in the
syslogger files, he's unlikely to go look in the eventlog.

regards, tom lane

On Tue, Jan 30, 2007 at 10:32:14AM -0500, Tom Lane wrote:
> Magnus Hagander <magnus(at)hagander(dot)net> writes:
> > So I still tthink it's a good idea. Even though it doesn't solve every
> > case, it solves a lot of them I think. And more importantly on that, I
> > don't see how it would *break* anything (given that it still fires only
> > when running as a service, when everything on stderr is just thrown away
> > anyway). Do you see suhc a failure case?
>
> The case I'm worried about is subprocess startup, where we haven't yet
> been able to re-set any of these variables correctly. And yes, I think
> it's an issue: if a DBA is expecting to find PG error messages in the
> syslogger files, he's unlikely to go look in the eventlog.

But in that case, the syslogger is already running, right? So it'll pick
up the messages and drop them in the log as expected. Because we can't
start backends before the syslogger is up, and I think it's the first of
our subprocesses to start still?

You'll have problems if the syslogger keeps crashing, but if that
happens we will at least have the log that the syslogger is crashing.

I get the feeling I'm missing something, but I'm not sure what it is :-)

But I guess maybe the added check has to be not just (!syslogger_started)
but (!syslogger_started && is_postmaster)?

//Magnus

Magnus Hagander <magnus(at)hagander(dot)net> writes:
> But I guess maybe the added check has to be not just (!syslogger_started)
> but (!syslogger_started && is_postmaster)?

That would at least get you out of the problem of having to transmit the
syslogger_started flag to the backends...

regards, tom lane

On Tue, Jan 30, 2007 at 11:45:24AM -0500, Tom Lane wrote:
> Magnus Hagander <magnus(at)hagander(dot)net> writes:
> > But I guess maybe the added check has to be not just (!syslogger_started)
> > but (!syslogger_started && is_postmaster)?
>
> That would at least get you out of the problem of having to transmit the
> syslogger_started flag to the backends...

Here's a patch that does just this.

//Magnus

Magnus Hagander wrote:
> On Tue, Jan 30, 2007 at 11:45:24AM -0500, Tom Lane wrote:
>> Magnus Hagander <magnus(at)hagander(dot)net> writes:
>>> But I guess maybe the added check has to be not just (!syslogger_started)
>>> but (!syslogger_started && is_postmaster)?
>> That would at least get you out of the problem of having to transmit the
>> syslogger_started flag to the backends...
>
> Here's a patch that does just this.

Since nobody complained and it passed all my tests, I've gone ahead and
applied this patch to head and back-patched to 8.1 and 8.2.

//Magnus