Hi,
When I shut down the standby server just after setting up replication
environment and shutting down the primary, I found that it took
five seconds to complete the shutdown of the standby server. Note that
no WAL was generated between the setup of replication and the server
shutdown, in this case. That is, basically neither WAL replay nor
shutdown restart point didn't cause this issue, I think. Here are
the log messages in that standby. I have observed this issue some times
so far.
2020-09-17 21:29:54 JST [postmaster] sby1 LOG: received fast shutdown request
2020-09-17 21:29:54 JST [postmaster] sby1 LOG: aborting any active transactions
2020-09-17 21:29:59 JST [checkpointer] sby1 LOG: shutting down
2020-09-17 21:29:59 JST [checkpointer] sby1 LOG: restartpoint starting:
shutdown immediate
2020-09-17 21:29:59 JST [checkpointer] sby1 LOG: restartpoint complete: wrote
0 buffers (0.0%); 0 WAL file(s) added, 0 removed, 1 recycled; write=0.014 s,
sync=0.000 s, total=0.022 s; sync files=0, longest=0.000 s, average=0.000 s;
distance=16384 kB, estimate=16384 kB
2020-09-17 21:29:59 JST [checkpointer] sby1 LOG: recovery restart point at
0/5000060
2020-09-17 21:29:59 JST [postmaster] sby1 LOG: database system is shut down
Per my analysis, this issue could happen in the following way.
1. In WaitForWALToBecomeAvailable(), the startup proesss receives
the shutdown request during sleeping wal_retrieve_retry_interval.
2. In ReadRecord(), the startup process thinks no valid record available
and loops back to retry reading WAL from stream.
3. In WaitForWALToBecomeAvailable(), the startup proesss tries to
start up walreceiver and then waits for recoveryWakeupLatch.
4. After the timeout (5 seconds is used for that wait for recoveryWakeupLatch)
passes, HandleStartupProcInterrupts() is called and the shutdown request
is processed.
So waiting at #3 for recoveryWakeupLatch caused the delay of
the standby shutdown.
To avoid this issue, I think that ReadRecord() should call
HandleStartupProcInterrupts() whenever looping back to retry.
Patch attached. Thought?
Regards,
--
Fujii Masao
Advanced Computing Technology Center
Research and Development Headquarters
NTT DATA CORPORATION
diff --git a/src/backend/access/transam/xlog.c
b/src/backend/access/transam/xlog.c
index 61754312e2..faf8d9c4f0 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -4456,15 +4456,16 @@ ReadRecord(XLogReaderState *xlogreader, int emode,
*/
lastSourceFailed = false;
currentSource = XLOG_FROM_ANY;
-
- continue;
}
-
/* In standby mode, loop back to retry. Otherwise, give
up. */
- if (StandbyMode && !CheckForStandbyTrigger())
- continue;
- else
+ else if (!StandbyMode || CheckForStandbyTrigger())
return NULL;
+
+ /*
+ * This possibly-long loop needs to handle interrupts
of startup
+ * process.
+ */
+ HandleStartupProcInterrupts();
}
}
}
