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.

diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index 6ea92b41022b531ad814ebbb3f5e34cf5c1490f7..d173609bc5de529a724cc602380c383074df1ab0 100644 (file)
--- 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 f6b79a9968969dda533777e610e046fd4bab01b8..8552c3d6b84379a1221c81af3299c57d694ccbda 100644 (file)
--- 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)