At Tue, 28 Jan 2020 11:18:14 -0300, Alvaro Herrera <alvhe...@2ndquadrant.com>
wrote in
> > xlog.c:7329: (similar code exists at line 9332)
> > > ereport(LOG,
> > > (errmsg("redo done at %X/%X",
> > > (uint32) (ReadRecPtr >> 32), (uint32)
> > > ReadRecPtr)));
> > > xtime = GetLatestXTime();
> > > if (xtime)
> > > ereport(LOG,
> > > (errmsg("last completed transaction was at log
> > > time %s",
> > > timestamptz_to_str(xtime))));
> >
> > This code assumes (and the name GetLatestXTime() suggests, I first
> > noticed that here..) that the timestamp comes from commit/abort logs,
> > so otherwise it shows a wrong timestamp. We shouldn't update the
> > variable by other than that kind of records.
>
> Hmm, that's terrible. GetLatestXTime() being displayed user-visibly for
> "last transaction completion" but having it include unrelated things
> such as restore points is terrible. One idea is to should split it in
> two: one exclusively for transaction commit/abort, and another for all
> WAL activity. That way, the former can be used for that message, and
> the latter for standby replay reports. However, that might be
> overengineering, if the only thing that the former is that one LOG
> message; instead changing the log message to state that the time is for
> other activity, as you suggest, is simpler and has no downside that I
> can see.
Perhaps we can use ControlData->checkPointCopy.time instead. It misses
checkpoint records intermittently but works in general.
But as more significant issue, nowadays PostgreSQL doesn't run a
checkpoint if it is really inactive (that is, if no "important" WAL
records have issued.).
regards.
--
Kyotaro Horiguchi
NTT Open Source Software Center
