Shutdown TRUE?

Peter Eisentraut <peter_e@gmx.net> writes:

When the server starts I see something like
DEBUG: redo record is at 0/146ED4; undo record is at 0/0; shutdown TRUE

but what does "shutdown TRUE" mean? It doesn't mean "I'm shutting down"
nor "the last shutdown was successful", so it's not very obvious.

It means the latest checkpoint record in the WAL log has the shutdown bit
set, implying that there was an intentional shutdown. This should be
redundant with the control-file-state-field info that's reported a line
or two earlier --- but I suppose it would be interesting for debugging
if it didn't agree.

Feel free to change the message wording...

regards, tom lane

Peter Eisentraut <peter_e@gmx.net> writes:

Tom Lane writes:

It means the latest checkpoint record in the WAL log has the shutdown bit
set, implying that there was an intentional shutdown.

I'd hardly consider a kill -9 an intentional shutdown. ???

Huh? If you zap the postmaster with kill -9, the last checkpoint record
in the WAL log will not have the shutdown bit set.

regards, tom lane

Tom Lane writes:

It means the latest checkpoint record in the WAL log has the shutdown bit
set, implying that there was an intentional shutdown.

I'd hardly consider a kill -9 an intentional shutdown. ???

--
Peter Eisentraut peter_e@gmx.net http://funkturm.homeip.net/~peter

Peter Eisentraut <peter_e@gmx.net> writes:

Tom Lane writes:

Huh? If you zap the postmaster with kill -9, the last checkpoint record
in the WAL log will not have the shutdown bit set.

It does here:

Had you actually done anything to the database between postmaster
startup and kill? If there's no reason to do a checkpoint then it
won't checkpoint, so the last checkpoint would be from the previous
incarnation. But under normal circumstances I see "shutdown FALSE"
here.

regards, tom lane

Tom Lane writes:

Huh? If you zap the postmaster with kill -9, the last checkpoint record
in the WAL log will not have the shutdown bit set.

It does here:

peter ~$ pg-install/bin/postmaster -D pg-install/var/data
DEBUG: database system was shut down at 2001-09-20 18:52:58 CEST
DEBUG: checkpoint record is at 0/146F54
DEBUG: redo record is at 0/146F54; undo record is at 0/0; shutdown TRUE
DEBUG: next transaction id: 136; next oid: 16579
DEBUG: database system is ready
Killed
peter ~$ pg-install/bin/postmaster -D pg-install/var/data
DEBUG: database system was interrupted at 2001-09-20 22:27:00 CEST
DEBUG: checkpoint record is at 0/146F54
DEBUG: redo record is at 0/146F54; undo record is at 0/0; shutdown TRUE
DEBUG: next transaction id: 136; next oid: 16579
DEBUG: database system was not properly shut down; automatic recovery in progress
DEBUG: ReadRecord: record with zero length at 0/146F94
DEBUG: redo is not required
DEBUG: database system is ready

--
Peter Eisentraut peter_e@gmx.net http://funkturm.homeip.net/~peter

Tom Lane writes:

Had you actually done anything to the database between postmaster
startup and kill?

I've run the regression tests several times (parallel and serial) and
killed the postmaster at different places, even killed a few backends in
between, actual redo happened, yet shutdown was invariably TRUE.

Another question I have is what is the significance of

ReadRecord: record with zero length at 0/D65C00

? It seems to occur at the end of every redo run, perhaps it simply means
end of records. At least it's not clear to the user whether this is
debug, info, warning, or error.

--
Peter Eisentraut peter_e@gmx.net http://funkturm.homeip.net/~peter

Peter Eisentraut <peter_e@gmx.net> writes:

Tom Lane writes:

Had you actually done anything to the database between postmaster
startup and kill?

I've run the regression tests several times (parallel and serial) and
killed the postmaster at different places, even killed a few backends in
between, actual redo happened, yet shutdown was invariably TRUE.

Hm. Do you have an especially long intra-checkpoint interval set in
postgresql.conf? I'd expect that if you'd done anything to the db and
then waited at least a checkpoint interval (or done a manual CHECKPOINT)
before killing the postmaster, you'd find a non-shutdown checkpoint
record. That's what I get anyway.

Another question I have is what is the significance of
ReadRecord: record with zero length at 0/D65C00
? It seems to occur at the end of every redo run, perhaps it simply means
end of records.

Yeah, that would be the normal symptom of reaching the end of the log.

At least it's not clear to the user whether this is debug, info,
warning, or error.

It's debug, and so labeled.

Possibly we need more elog levels than we have --- the stuff that comes
out at startup is not all of the same urgency, but DEBUG is the only
elog level we can use for it, really...

regards, tom lane