Add still more chattiness in server shutdown.

Further investigation says that there may be some slow operations after
we've finished ShutdownXLOG(), so add some more log messages to try to
isolate that.  This is all temporary code too.

diff --git a/src/backend/postmaster/postmaster.c b/src/backend/postmaster/postmaster.c
index 1337eabb3a5cc3129cf11fd6b0fd17f0a4ae31ae..a5fa1d4720af4d8d0631fd23d11a7618e1208cdc 100644 (file)
--- a/src/backend/postmaster/postmaster.c
+++ b/src/backend/postmaster/postmaster.c
@@ -2850,6 +2850,9 @@ reaper(SIGNAL_ARGS)
                                 */
                                Assert(Shutdown > NoShutdown);
 
+                               elog(LOG, "checkpointer dead at %s",
+                                        current_time_as_str());
+
                                /* Waken archiver for the last time */
                                if (PgArchPID != 0)
                                        signal_child(PgArchPID, SIGUSR2);
@@ -3711,6 +3714,9 @@ PostmasterStateMachine(void)
                        if (ReachedNormalRunning)
                                CancelBackup();
 
+                       elog(LOG, "all children dead at %s",
+                                current_time_as_str());
+
                        /* Normal exit from the postmaster is here */
                        ExitPostmaster(0);
                }

diff --git a/src/backend/storage/ipc/ipc.c b/src/backend/storage/ipc/ipc.c
index cc36b80699b4997cd46baaaef49aa23b5bca3d24..8db5f9ed326546664e4323e5f2710a4dcc88f6db 100644 (file)
--- a/src/backend/storage/ipc/ipc.c
+++ b/src/backend/storage/ipc/ipc.c
@@ -98,6 +98,8 @@ static int    on_proc_exit_index,
 void
 proc_exit(int code)
 {
+       bool noisy = AmCheckpointerProcess() || (getpid() == PostmasterPid);
+
        /* Clean up everything that must be cleaned up */
        proc_exit_prepare(code);
 
@@ -140,6 +142,10 @@ proc_exit(int code)
 
        elog(DEBUG3, "exit(%d)", code);
 
+       if (noisy)
+               elog(LOG, "calling exit(%d) at %s",
+                        code, current_time_as_str());
+
        exit(code);
 }
 
@@ -151,6 +157,8 @@ proc_exit(int code)
 static void
 proc_exit_prepare(int code)
 {
+       bool noisy = AmCheckpointerProcess() || (getpid() == PostmasterPid);
+
        /*
         * Once we set this flag, we are committed to exit.  Any ereport() will
         * NOT send control back to the main loop, but right back here.
@@ -197,8 +205,13 @@ proc_exit_prepare(int code)
         * possible.
         */
        while (--on_proc_exit_index >= 0)
+       {
+               if (noisy)
+                       elog(LOG, "doing on_proc_exit %d at %s",
+                                on_proc_exit_index, current_time_as_str());
                (*on_proc_exit_list[on_proc_exit_index].function) (code,
                                                                  on_proc_exit_list[on_proc_exit_index].arg);
+       }
 
        on_proc_exit_index = 0;
 }
@@ -214,6 +227,8 @@ proc_exit_prepare(int code)
 void
 shmem_exit(int code)
 {
+       bool noisy = AmCheckpointerProcess() || (getpid() == PostmasterPid);
+
        /*
         * Call before_shmem_exit callbacks.
         *
@@ -225,8 +240,13 @@ shmem_exit(int code)
        elog(DEBUG3, "shmem_exit(%d): %d before_shmem_exit callbacks to make",
                 code, before_shmem_exit_index);
        while (--before_shmem_exit_index >= 0)
+       {
+               if (noisy)
+                       elog(LOG, "doing before_shmem_exit %d at %s",
+                                before_shmem_exit_index, current_time_as_str());
                (*before_shmem_exit_list[before_shmem_exit_index].function) (code,
                                                before_shmem_exit_list[before_shmem_exit_index].arg);
+       }
        before_shmem_exit_index = 0;
 
        /*
@@ -258,8 +278,13 @@ shmem_exit(int code)
        elog(DEBUG3, "shmem_exit(%d): %d on_shmem_exit callbacks to make",
                 code, on_shmem_exit_index);
        while (--on_shmem_exit_index >= 0)
+       {
+               if (noisy)
+                       elog(LOG, "doing on_shmem_exit %d at %s",
+                                on_shmem_exit_index, current_time_as_str());
                (*on_shmem_exit_list[on_shmem_exit_index].function) (code,
                                                                on_shmem_exit_list[on_shmem_exit_index].arg);
+       }
        on_shmem_exit_index = 0;
 }