1
0
mirror of https://github.com/postgres/postgres.git synced 2025-06-29 10:41:53 +03:00

Temporarily make pg_ctl and server shutdown a whole lot chattier.

This is a quick hack, due to be reverted when its purpose has been served,
to try to gather information about why some of the buildfarm critters
regularly fail with "postmaster does not shut down" complaints.  Maybe they
are just really overloaded, but maybe something else is going on.  Hence,
instrument pg_ctl to print the current time when it starts waiting for
postmaster shutdown and when it gives up, and add a lot of logging of the
current time in the server's checkpoint and shutdown code paths.

No attempt has been made to make this pretty.  I'm not even totally sure
if it will build on Windows, but we'll soon find out.
This commit is contained in:
Tom Lane
2016-02-08 18:43:11 -05:00
parent 0231f83856
commit 3971f64843
7 changed files with 125 additions and 8 deletions

View File

@ -7927,7 +7927,7 @@ ShutdownXLOG(int code, Datum arg)
{
/* Don't be chatty in standalone mode */
ereport(IsPostmasterEnvironment ? LOG : NOTICE,
(errmsg("shutting down")));
(errmsg("shutting down at %s", current_time_as_str())));
if (RecoveryInProgress())
CreateRestartPoint(CHECKPOINT_IS_SHUTDOWN | CHECKPOINT_IMMEDIATE);
@ -7943,15 +7943,28 @@ ShutdownXLOG(int code, Datum arg)
RequestXLogSwitch();
CreateCheckPoint(CHECKPOINT_IS_SHUTDOWN | CHECKPOINT_IMMEDIATE);
elog(IsPostmasterEnvironment ? LOG : NOTICE,
"shutdown checkpoint complete at %s",
current_time_as_str());
}
ShutdownCLOG();
elog(IsPostmasterEnvironment ? LOG : NOTICE,
"ShutdownCLOG() complete at %s",
current_time_as_str());
ShutdownCommitTs();
elog(IsPostmasterEnvironment ? LOG : NOTICE,
"ShutdownCommitTs() complete at %s",
current_time_as_str());
ShutdownSUBTRANS();
elog(IsPostmasterEnvironment ? LOG : NOTICE,
"ShutdownSUBTRANS() complete at %s",
current_time_as_str());
ShutdownMultiXact();
/* Don't be chatty in standalone mode */
ereport(IsPostmasterEnvironment ? LOG : NOTICE,
(errmsg("database system is shut down")));
(errmsg("database system is shut down at %s", current_time_as_str())));
}
/*
@ -8602,19 +8615,45 @@ CreateEndOfRecoveryRecord(void)
static void
CheckPointGuts(XLogRecPtr checkPointRedo, int flags)
{
elog(IsPostmasterEnvironment ? LOG : NOTICE,
"CheckPointGuts starting at %s", current_time_as_str());
CheckPointCLOG();
elog(IsPostmasterEnvironment ? LOG : NOTICE,
"CheckPointCLOG() done at %s", current_time_as_str());
CheckPointCommitTs();
elog(IsPostmasterEnvironment ? LOG : NOTICE,
"CheckPointCommitTs() done at %s", current_time_as_str());
CheckPointSUBTRANS();
elog(IsPostmasterEnvironment ? LOG : NOTICE,
"CheckPointSUBTRANS() done at %s", current_time_as_str());
CheckPointMultiXact();
elog(IsPostmasterEnvironment ? LOG : NOTICE,
"CheckPointMultiXact() done at %s", current_time_as_str());
CheckPointPredicate();
elog(IsPostmasterEnvironment ? LOG : NOTICE,
"CheckPointPredicate() done at %s", current_time_as_str());
CheckPointRelationMap();
elog(IsPostmasterEnvironment ? LOG : NOTICE,
"CheckPointRelationMap() done at %s", current_time_as_str());
CheckPointReplicationSlots();
elog(IsPostmasterEnvironment ? LOG : NOTICE,
"CheckPointReplicationSlots() done at %s", current_time_as_str());
CheckPointSnapBuild();
elog(IsPostmasterEnvironment ? LOG : NOTICE,
"CheckPointSnapBuild() done at %s", current_time_as_str());
CheckPointLogicalRewriteHeap();
elog(IsPostmasterEnvironment ? LOG : NOTICE,
"CheckPointLogicalRewriteHeap() done at %s", current_time_as_str());
CheckPointBuffers(flags); /* performs all required fsyncs */
elog(IsPostmasterEnvironment ? LOG : NOTICE,
"CheckPointBuffers() done at %s", current_time_as_str());
CheckPointReplicationOrigin();
elog(IsPostmasterEnvironment ? LOG : NOTICE,
"CheckPointReplicationOrigin() done at %s", current_time_as_str());
/* We deliberately delay 2PC checkpointing as long as possible */
CheckPointTwoPhase(checkPointRedo);
elog(IsPostmasterEnvironment ? LOG : NOTICE,
"CheckPointGuts done at %s", current_time_as_str());
}
/*