From 41d505a7ffaf8c1678b931e15f74469c84fbb91e Mon Sep 17 00:00:00 2001
From: Tom Lane <tgl@sss.pgh.pa.us>
Date: Tue, 9 Feb 2016 19:36:21 -0500
Subject: [PATCH] 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.
---
 src/backend/postmaster/postmaster.c |  6 ++++++
 src/backend/storage/ipc/ipc.c       | 25 +++++++++++++++++++++++++
 2 files changed, 31 insertions(+)

diff --git a/src/backend/postmaster/postmaster.c b/src/backend/postmaster/postmaster.c
index 1337eabb3a..a5fa1d4720 100644
--- 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 cc36b80699..8db5f9ed32 100644
--- 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;
 }
 
-- 
2.40.0