Re: Something is fairly whacko about shutdown in CVS HEAD

Tom Lane wrote:
> I'm seeing two sets of shutdown messages, and apparently a second
> shutdown checkpoint being forced, during a normal database stop:
>
> 2007-06-30 14:21:00 EDT 9644 LOG: received smart shutdown request
> 2007-06-30 14:21:00 EDT 9647 LOG: shutting down
> 2007-06-30 14:21:00 EDT 9647 LOG: checkpoint starting: shutdown immediate
> 2007-06-30 14:21:00 EDT 9647 LOG: checkpoint complete: wrote 23 buffers (0.6%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=0.003 s, sync=0.178 s, total=0.237 s
> 2007-06-30 14:21:00 EDT 9647 LOG: database system is shut down
> 2007-06-30 14:21:00 EDT 9644 LOG: background writer process (PID 9647) exited with exit code 0
> 2007-06-30 14:21:00 EDT 9644 LOG: terminating any other active server processes
> 2007-06-30 14:21:00 EDT 9644 LOG: all server processes terminated; reinitializing
> 2007-06-30 14:21:00 EDT 9654 LOG: database system was shut down at 2007-06-30 14:21:00 EDT
> 2007-06-30 14:21:01 EDT 9655 LOG: shutting down
> 2007-06-30 14:21:01 EDT 9655 LOG: checkpoint starting: shutdown immediate
> 2007-06-30 14:21:01 EDT 9655 LOG: checkpoint complete: wrote 0 buffers (0.0%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=0.000 s, sync=0.000 s, total=0.041 s
> 2007-06-30 14:21:01 EDT 9655 LOG: database system is shut down
>
> I haven't looked for the cause yet but I suspect it's got something to
> do with this patch:
> http://archives.postgresql.org/pgsql-committers/2007-06/msg00285.php
> Either that or somebody else broke it recently.

Huh, I can't reproduce it here.

2007-06-30 20:51:27 CLT 23221 LOG: received smart shutdown request
2007-06-30 20:51:27 CLT 23223 LOG: shutting down
2007-06-30 20:51:27 CLT 23225 LOG: autovacuum launcher shutting down
2007-06-30 20:51:27 CLT 23223 LOG: checkpoint starting: shutdown immediate
2007-06-30 20:51:27 CLT 23223 LOG: checkpoint complete: wrote 474 buffers (15.4%); 0 transaction log file(s) added, 0 removed, 1 recycled; write=0.016 s, sync=0.084 s, total=0.124 s
2007-06-30 20:51:27 CLT 23223 LOG: database system is shut down

In your test output, it looks like the bgwriter is exiting early with code 0
which makes postmaster upset, so it restarts it. Or maybe bgwriter
exits as expected but the postmaster is denying reality.

--
Alvaro Herrera http://www.amazon.com/gp/registry/DXLWNGRJD34J
"Investigación es lo que hago cuando no sé lo que estoy haciendo"
(Wernher von Braun)