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)