From 7351e18286ec83461b386e23328d65fd4a538bba Mon Sep 17 00:00:00 2001
From: Tom Lane <tgl@sss.pgh.pa.us>
Date: Tue, 9 Feb 2016 11:21:46 -0500
Subject: [PATCH] Add more chattiness in server shutdown.
Early returns from the buildfarm show that there's a bit of a gap in the
logging I added in 3971f64843b02e4a: the portion of CreateCheckPoint()
after CheckPointGuts() can take a fair amount of time. Add a few more
log messages in that section of code. This too shall be reverted later.
---
src/backend/access/transam/xlog.c | 16 ++++++++++++++++
src/backend/storage/smgr/md.c | 5 +++++
2 files changed, 21 insertions(+)
diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index 6ea92b41022..d173609bc5d 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -8436,6 +8436,9 @@ CreateCheckPoint(int flags)
XLogFlush(recptr);
+ elog(IsPostmasterEnvironment ? LOG : NOTICE,
+ "checkpoint WAL record flushed at %s", current_time_as_str());
+
/*
* We mustn't write any new WAL after a shutdown checkpoint, or it will be
* overwritten at next startup. No-one should even try, this just allows
@@ -8491,6 +8494,9 @@ CreateCheckPoint(int flags)
UpdateControlFile();
LWLockRelease(ControlFileLock);
+ elog(IsPostmasterEnvironment ? LOG : NOTICE,
+ "pg_control updated at %s", current_time_as_str());
+
/* Update shared-memory copy of checkpoint XID/epoch */
SpinLockAcquire(&XLogCtl->info_lck);
XLogCtl->ckptXidEpoch = checkPoint.nextXidEpoch;
@@ -8508,6 +8514,9 @@ CreateCheckPoint(int flags)
*/
smgrpostckpt();
+ elog(IsPostmasterEnvironment ? LOG : NOTICE,
+ "smgrpostckpt() done at %s", current_time_as_str());
+
/*
* Delete old log files (those no longer needed even for previous
* checkpoint or the standbys in XLOG streaming).
@@ -8523,6 +8532,9 @@ CreateCheckPoint(int flags)
KeepLogSeg(recptr, &_logSegNo);
_logSegNo--;
RemoveOldXlogFiles(_logSegNo, PriorRedoPtr, recptr);
+
+ elog(IsPostmasterEnvironment ? LOG : NOTICE,
+ "RemoveOldXlogFiles() done at %s", current_time_as_str());
}
/*
@@ -8540,7 +8552,11 @@ CreateCheckPoint(int flags)
* StartupSUBTRANS hasn't been called yet.
*/
if (!RecoveryInProgress())
+ {
TruncateSUBTRANS(GetOldestXmin(NULL, false));
+ elog(IsPostmasterEnvironment ? LOG : NOTICE,
+ "TruncateSUBTRANS() done at %s", current_time_as_str());
+ }
/* Real work is done, but log and update stats before releasing lock. */
LogCheckpointEnd(false);
diff --git a/src/backend/storage/smgr/md.c b/src/backend/storage/smgr/md.c
index f6b79a99689..8552c3d6b84 100644
--- a/src/backend/storage/smgr/md.c
+++ b/src/backend/storage/smgr/md.c
@@ -1314,6 +1314,11 @@ mdpostckpt(void)
if (entry->cycle_ctr == mdckpt_cycle_ctr)
break;
+ if ((list_length(pendingUnlinks) % 1024) == 0)
+ elog(IsPostmasterEnvironment ? LOG : NOTICE,
+ "in mdpostckpt, %d unlinks remain to do at %s",
+ list_length(pendingUnlinks), current_time_as_str());
+
/* Unlink the file */
path = relpathperm(entry->rnode, MAIN_FORKNUM);
if (unlink(path) < 0)
--
GitLab