From 7351e18286ec83461b386e23328d65fd4a538bba Mon Sep 17 00:00:00 2001 From: Tom Lane 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 6ea92b4102..d173609bc5 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 f6b79a9968..8552c3d6b8 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) -- 2.40.0