Skip to content

Commit c5e9b77

Browse files
tglsfdctglsfdc
committed
Revert "Temporarily make pg_ctl and server shutdown a whole lot chattier."
This reverts commit 3971f64 and a couple of followon debugging commits; I think we've learned what we can from them.
1 parent 79a7ff0 commit c5e9b77

File tree

9 files changed

+8
-177
lines changed

9 files changed

+8
-177
lines changed

‎src/backend/access/transam/xlog.c

+2-57
Original file line numberDiff line numberDiff line change
@@ -7927,7 +7927,7 @@ ShutdownXLOG(int code, Datum arg)
79277927
{
79287928
/* Don't be chatty in standalone mode */
79297929
ereport(IsPostmasterEnvironment ? LOG : NOTICE,
7930-
(errmsg("shutting down at %s", current_time_as_str())));
7930+
(errmsg("shutting down")));
79317931

79327932
if (RecoveryInProgress())
79337933
CreateRestartPoint(CHECKPOINT_IS_SHUTDOWN | CHECKPOINT_IMMEDIATE);
@@ -7943,28 +7943,15 @@ ShutdownXLOG(int code, Datum arg)
79437943
RequestXLogSwitch();
79447944

79457945
CreateCheckPoint(CHECKPOINT_IS_SHUTDOWN | CHECKPOINT_IMMEDIATE);
7946-
7947-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
7948-
"shutdown checkpoint complete at %s",
7949-
current_time_as_str());
79507946
}
79517947
ShutdownCLOG();
7952-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
7953-
"ShutdownCLOG() complete at %s",
7954-
current_time_as_str());
79557948
ShutdownCommitTs();
7956-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
7957-
"ShutdownCommitTs() complete at %s",
7958-
current_time_as_str());
79597949
ShutdownSUBTRANS();
7960-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
7961-
"ShutdownSUBTRANS() complete at %s",
7962-
current_time_as_str());
79637950
ShutdownMultiXact();
79647951

79657952
/* Don't be chatty in standalone mode */
79667953
ereport(IsPostmasterEnvironment ? LOG : NOTICE,
7967-
(errmsg("database system is shut down at %s", current_time_as_str())));
7954+
(errmsg("database system is shut down")));
79687955
}
79697956

79707957
/*
@@ -8436,9 +8423,6 @@ CreateCheckPoint(int flags)
84368423

84378424
XLogFlush(recptr);
84388425

8439-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
8440-
"checkpoint WAL record flushed at %s", current_time_as_str());
8441-
84428426
/*
84438427
* We mustn't write any new WAL after a shutdown checkpoint, or it will be
84448428
* overwritten at next startup. No-one should even try, this just allows
@@ -8494,9 +8478,6 @@ CreateCheckPoint(int flags)
84948478
UpdateControlFile();
84958479
LWLockRelease(ControlFileLock);
84968480

8497-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
8498-
"pg_control updated at %s", current_time_as_str());
8499-
85008481
/* Update shared-memory copy of checkpoint XID/epoch */
85018482
SpinLockAcquire(&XLogCtl->info_lck);
85028483
XLogCtl->ckptXidEpoch = checkPoint.nextXidEpoch;
@@ -8514,9 +8495,6 @@ CreateCheckPoint(int flags)
85148495
*/
85158496
smgrpostckpt();
85168497

8517-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
8518-
"smgrpostckpt() done at %s", current_time_as_str());
8519-
85208498
/*
85218499
* Delete old log files (those no longer needed even for previous
85228500
* checkpoint or the standbys in XLOG streaming).
@@ -8532,9 +8510,6 @@ CreateCheckPoint(int flags)
85328510
KeepLogSeg(recptr, &_logSegNo);
85338511
_logSegNo--;
85348512
RemoveOldXlogFiles(_logSegNo, PriorRedoPtr, recptr);
8535-
8536-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
8537-
"RemoveOldXlogFiles() done at %s", current_time_as_str());
85388513
}
85398514

85408515
/*
@@ -8552,11 +8527,7 @@ CreateCheckPoint(int flags)
85528527
* StartupSUBTRANS hasn't been called yet.
85538528
*/
85548529
if (!RecoveryInProgress())
8555-
{
85568530
TruncateSUBTRANS(GetOldestXmin(NULL, false));
8557-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
8558-
"TruncateSUBTRANS() done at %s", current_time_as_str());
8559-
}
85608531

85618532
/* Real work is done, but log and update stats before releasing lock. */
85628533
LogCheckpointEnd(false);
@@ -8631,45 +8602,19 @@ CreateEndOfRecoveryRecord(void)
86318602
static void
86328603
CheckPointGuts(XLogRecPtr checkPointRedo, int flags)
86338604
{
8634-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
8635-
"CheckPointGuts starting at %s", current_time_as_str());
86368605
CheckPointCLOG();
8637-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
8638-
"CheckPointCLOG() done at %s", current_time_as_str());
86398606
CheckPointCommitTs();
8640-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
8641-
"CheckPointCommitTs() done at %s", current_time_as_str());
86428607
CheckPointSUBTRANS();
8643-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
8644-
"CheckPointSUBTRANS() done at %s", current_time_as_str());
86458608
CheckPointMultiXact();
8646-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
8647-
"CheckPointMultiXact() done at %s", current_time_as_str());
86488609
CheckPointPredicate();
8649-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
8650-
"CheckPointPredicate() done at %s", current_time_as_str());
86518610
CheckPointRelationMap();
8652-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
8653-
"CheckPointRelationMap() done at %s", current_time_as_str());
86548611
CheckPointReplicationSlots();
8655-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
8656-
"CheckPointReplicationSlots() done at %s", current_time_as_str());
86578612
CheckPointSnapBuild();
8658-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
8659-
"CheckPointSnapBuild() done at %s", current_time_as_str());
86608613
CheckPointLogicalRewriteHeap();
8661-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
8662-
"CheckPointLogicalRewriteHeap() done at %s", current_time_as_str());
86638614
CheckPointBuffers(flags); /* performs all required fsyncs */
8664-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
8665-
"CheckPointBuffers() done at %s", current_time_as_str());
86668615
CheckPointReplicationOrigin();
8667-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
8668-
"CheckPointReplicationOrigin() done at %s", current_time_as_str());
86698616
/* We deliberately delay 2PC checkpointing as long as possible */
86708617
CheckPointTwoPhase(checkPointRedo);
8671-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
8672-
"CheckPointGuts done at %s", current_time_as_str());
86738618
}
86748619

86758620
/*

‎src/backend/postmaster/autovacuum.c

+1-2
Original file line numberDiff line numberDiff line change
@@ -772,8 +772,7 @@ AutoVacLauncherMain(int argc, char *argv[])
772772
/* Normal exit from the autovac launcher is here */
773773
shutdown:
774774
ereport(LOG,
775-
(errmsg("autovacuum launcher shutting down at %s",
776-
current_time_as_str())));
775+
(errmsg("autovacuum launcher shutting down")));
777776
AutoVacuumShmem->av_launcherpid = 0;
778777

779778
proc_exit(0); /* done */

‎src/backend/postmaster/postmaster.c

+3-12
Original file line numberDiff line numberDiff line change
@@ -2538,8 +2538,7 @@ pmdie(SIGNAL_ARGS)
25382538
break;
25392539
Shutdown = SmartShutdown;
25402540
ereport(LOG,
2541-
(errmsg("received smart shutdown request at %s",
2542-
current_time_as_str())));
2541+
(errmsg("received smart shutdown request")));
25432542
#ifdef USE_SYSTEMD
25442543
sd_notify(0, "STOPPING=1");
25452544
#endif
@@ -2594,8 +2593,7 @@ pmdie(SIGNAL_ARGS)
25942593
break;
25952594
Shutdown = FastShutdown;
25962595
ereport(LOG,
2597-
(errmsg("received fast shutdown request at %s",
2598-
current_time_as_str())));
2596+
(errmsg("received fast shutdown request")));
25992597
#ifdef USE_SYSTEMD
26002598
sd_notify(0, "STOPPING=1");
26012599
#endif
@@ -2658,8 +2656,7 @@ pmdie(SIGNAL_ARGS)
26582656
break;
26592657
Shutdown = ImmediateShutdown;
26602658
ereport(LOG,
2661-
(errmsg("received immediate shutdown request at %s",
2662-
current_time_as_str())));
2659+
(errmsg("received immediate shutdown request")));
26632660
#ifdef USE_SYSTEMD
26642661
sd_notify(0, "STOPPING=1");
26652662
#endif
@@ -2850,9 +2847,6 @@ reaper(SIGNAL_ARGS)
28502847
*/
28512848
Assert(Shutdown > NoShutdown);
28522849

2853-
elog(LOG, "checkpointer dead at %s",
2854-
current_time_as_str());
2855-
28562850
/* Waken archiver for the last time */
28572851
if (PgArchPID != 0)
28582852
signal_child(PgArchPID, SIGUSR2);
@@ -3714,9 +3708,6 @@ PostmasterStateMachine(void)
37143708
if (ReachedNormalRunning)
37153709
CancelBackup();
37163710

3717-
elog(LOG, "all children dead at %s",
3718-
current_time_as_str());
3719-
37203711
/* Normal exit from the postmaster is here */
37213712
ExitPostmaster(0);
37223713
}

‎src/backend/storage/buffer/bufmgr.c

-13
Original file line numberDiff line numberDiff line change
@@ -1691,10 +1691,6 @@ BufferSync(int flags)
16911691
UnlockBufHdr(bufHdr);
16921692
}
16931693

1694-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
1695-
"BufferSync(%x) beginning to write %d buffers at %s",
1696-
flags, num_to_write, current_time_as_str());
1697-
16981694
if (num_to_write == 0)
16991695
return; /* nothing to do */
17001696

@@ -1749,11 +1745,6 @@ BufferSync(int flags)
17491745
if (num_written >= num_to_write)
17501746
break;
17511747

1752-
if ((num_written % 1024) == 0)
1753-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
1754-
"BufferSync(%x) wrote %d/%d buffers at %s",
1755-
flags, num_written, num_to_write, current_time_as_str());
1756-
17571748
/*
17581749
* Sleep to throttle our I/O rate.
17591750
*/
@@ -1765,10 +1756,6 @@ BufferSync(int flags)
17651756
buf_id = 0;
17661757
}
17671758

1768-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
1769-
"BufferSync(%x) done, wrote %d/%d buffers at %s",
1770-
flags, num_written, num_to_write, current_time_as_str());
1771-
17721759
/*
17731760
* Update checkpoint statistics. As noted above, this doesn't include
17741761
* buffers written by other backends or bgwriter scan.

‎src/backend/storage/ipc/ipc.c

-25
Original file line numberDiff line numberDiff line change
@@ -98,8 +98,6 @@ static int on_proc_exit_index,
9898
void
9999
proc_exit(int code)
100100
{
101-
bool noisy = AmCheckpointerProcess() || (getpid() == PostmasterPid);
102-
103101
/* Clean up everything that must be cleaned up */
104102
proc_exit_prepare(code);
105103

@@ -142,10 +140,6 @@ proc_exit(int code)
142140

143141
elog(DEBUG3, "exit(%d)", code);
144142

145-
if (noisy)
146-
elog(LOG, "calling exit(%d) at %s",
147-
code, current_time_as_str());
148-
149143
exit(code);
150144
}
151145

@@ -157,8 +151,6 @@ proc_exit(int code)
157151
static void
158152
proc_exit_prepare(int code)
159153
{
160-
bool noisy = AmCheckpointerProcess() || (getpid() == PostmasterPid);
161-
162154
/*
163155
* Once we set this flag, we are committed to exit. Any ereport() will
164156
* NOT send control back to the main loop, but right back here.
@@ -205,13 +197,8 @@ proc_exit_prepare(int code)
205197
* possible.
206198
*/
207199
while (--on_proc_exit_index >= 0)
208-
{
209-
if (noisy)
210-
elog(LOG, "doing on_proc_exit %d at %s",
211-
on_proc_exit_index, current_time_as_str());
212200
(*on_proc_exit_list[on_proc_exit_index].function) (code,
213201
on_proc_exit_list[on_proc_exit_index].arg);
214-
}
215202

216203
on_proc_exit_index = 0;
217204
}
@@ -227,8 +214,6 @@ proc_exit_prepare(int code)
227214
void
228215
shmem_exit(int code)
229216
{
230-
bool noisy = AmCheckpointerProcess() || (getpid() == PostmasterPid);
231-
232217
/*
233218
* Call before_shmem_exit callbacks.
234219
*
@@ -240,13 +225,8 @@ shmem_exit(int code)
240225
elog(DEBUG3, "shmem_exit(%d): %d before_shmem_exit callbacks to make",
241226
code, before_shmem_exit_index);
242227
while (--before_shmem_exit_index >= 0)
243-
{
244-
if (noisy)
245-
elog(LOG, "doing before_shmem_exit %d at %s",
246-
before_shmem_exit_index, current_time_as_str());
247228
(*before_shmem_exit_list[before_shmem_exit_index].function) (code,
248229
before_shmem_exit_list[before_shmem_exit_index].arg);
249-
}
250230
before_shmem_exit_index = 0;
251231

252232
/*
@@ -278,13 +258,8 @@ shmem_exit(int code)
278258
elog(DEBUG3, "shmem_exit(%d): %d on_shmem_exit callbacks to make",
279259
code, on_shmem_exit_index);
280260
while (--on_shmem_exit_index >= 0)
281-
{
282-
if (noisy)
283-
elog(LOG, "doing on_shmem_exit %d at %s",
284-
on_shmem_exit_index, current_time_as_str());
285261
(*on_shmem_exit_list[on_shmem_exit_index].function) (code,
286262
on_shmem_exit_list[on_shmem_exit_index].arg);
287-
}
288263
on_shmem_exit_index = 0;
289264
}
290265

‎src/backend/storage/smgr/md.c

-5
Original file line numberDiff line numberDiff line change
@@ -1314,11 +1314,6 @@ mdpostckpt(void)
13141314
if (entry->cycle_ctr == mdckpt_cycle_ctr)
13151315
break;
13161316

1317-
if ((list_length(pendingUnlinks) % 1024) == 0)
1318-
elog(IsPostmasterEnvironment ? LOG : NOTICE,
1319-
"in mdpostckpt, %d unlinks remain to do at %s",
1320-
list_length(pendingUnlinks), current_time_as_str());
1321-
13221317
/* Unlink the file */
13231318
path = relpathperm(entry->rnode, MAIN_FORKNUM);
13241319
if (unlink(path) < 0)

‎src/backend/utils/init/miscinit.c

-28
Original file line numberDiff line numberDiff line change
@@ -691,31 +691,6 @@ GetUserNameFromId(Oid roleid, bool noerr)
691691
return result;
692692
}
693693

694-
/*
695-
* Quick hack.
696-
*/
697-
const char *
698-
current_time_as_str(void)
699-
{
700-
static char buf[128];
701-
struct timeval now_timeval;
702-
pg_time_t now;
703-
char msbuf[8];
704-
705-
gettimeofday(&now_timeval, NULL);
706-
now = (pg_time_t) now_timeval.tv_sec;
707-
708-
pg_strftime(buf, sizeof(buf),
709-
/* leave room for milliseconds... */
710-
"%Y-%m-%d %H:%M:%S %Z",
711-
pg_localtime(&now, log_timezone));
712-
713-
/* 'paste' milliseconds into place... */
714-
sprintf(msbuf, ".%03d", (int) (now_timeval.tv_usec / 1000));
715-
memcpy(buf + 19, msbuf, 4);
716-
717-
return buf;
718-
}
719694

720695
/*-------------------------------------------------------------------------
721696
* Interlock-file support
@@ -749,9 +724,6 @@ UnlinkLockFiles(int status, Datum arg)
749724
}
750725
/* Since we're about to exit, no need to reclaim storage */
751726
lock_files = NIL;
752-
753-
if (IsPostmasterEnvironment)
754-
elog(LOG, "lock files all released at %s", current_time_as_str());
755727
}
756728

757729
/*

0 commit comments

Comments
 (0)